From 6d95388b254c3838634e5c316416401892c5450d Mon Sep 17 00:00:00 2001 From: Eduard Kaverinskyi Date: Sat, 18 Jan 2025 17:15:32 +0100 Subject: [PATCH 01/16] whois/worker.py: fix worker to use DeviceRepository Signed-off-by: Eduard Kaverinskyi --- whois/worker.py | 18 +++++++++--------- 1 file changed, 9 insertions(+), 9 deletions(-) diff --git a/whois/worker.py b/whois/worker.py index 2dd41a9..937596d 100644 --- a/whois/worker.py +++ b/whois/worker.py @@ -2,12 +2,14 @@ import time from datetime import datetime, timezone -from whois.data.db.database import Device, db +from whois.data.db.database import Database +from whois.data.repository.device_repository import DeviceRepository, Device from whois.mikrotik import fetch_leases from whois.settings import production logger = logging.getLogger("mikrotik-worker") - +database = Database() +device_repository = DeviceRepository(database) def update_devices() -> int: leases = fetch_leases( @@ -15,13 +17,11 @@ def update_devices() -> int: ) for lease in leases: - with db.atomic(): - last_seen_date = datetime.now(timezone.utc) - lease.last_seen - Device.update_or_create( - mac_address=lease.mac_address, - last_seen=last_seen_date, - hostname=lease.host_name, - ) + device = Device(lease.mac_address, lease.host_name, lease.last_seen) + if device_repository.get_by_mac_address(lease.mac_address): + device_repository.update(device) + else: + device_repository.insert(device) return len(leases) From dd92e1269e0c64c20c667b393cdb37a33f6fc7ce Mon Sep 17 00:00:00 2001 From: Eduard Kaverinskyi Date: Sat, 18 Jan 2025 17:15:53 +0100 Subject: [PATCH 02/16] whois/worker.py: clean unused imports (date, datetime) Signed-off-by: Eduard Kaverinskyi --- whois/worker.py | 1 - 1 file changed, 1 deletion(-) diff --git a/whois/worker.py b/whois/worker.py index 937596d..d8d1a9e 100644 --- a/whois/worker.py +++ b/whois/worker.py @@ -1,6 +1,5 @@ import logging import time -from datetime import datetime, timezone from whois.data.db.database import Database from whois.data.repository.device_repository import DeviceRepository, Device From 0088c6afba039ba99327e20f5a65e5ead439a429 Mon Sep 17 00:00:00 2001 From: Eduard Kaverinskyi Date: Sat, 18 Jan 2025 17:16:26 +0100 Subject: [PATCH 03/16] db/database.py: clean unused imports Signed-off-by: Eduard Kaverinskyi --- whois/data/db/database.py | 2 -- 1 file changed, 2 deletions(-) diff --git a/whois/data/db/database.py b/whois/data/db/database.py index aaacf44..7b5f688 100644 --- a/whois/data/db/database.py +++ b/whois/data/db/database.py @@ -1,9 +1,7 @@ import logging import os -from typing import Callable import sqlalchemy as db -from sqlalchemy.orm import Session from whois.data.db.base import Base from whois.data.table.device import DeviceTable From 3972f3d63d4ea3c45d36ce74a3bf28f5dc033602 Mon Sep 17 00:00:00 2001 From: Eduard Kaverinskyi Date: Sat, 18 Jan 2025 17:52:52 +0100 Subject: [PATCH 04/16] db/database.py: improve database logs Signed-off-by: Eduard Kaverinskyi --- whois/data/db/database.py | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/whois/data/db/database.py b/whois/data/db/database.py index 7b5f688..e3359fe 100644 --- a/whois/data/db/database.py +++ b/whois/data/db/database.py @@ -24,6 +24,7 @@ def __init__(self, db_url: str = None): force=True, ) + self.logger.debug(f'Creating engine for "{db_url}"') self.engine = db.create_engine(db_url) self.metadata = db.MetaData() self.connection = None @@ -37,23 +38,23 @@ def is_connected(self) -> bool: return self.connection is not None def connect(self) -> None: - self.logger.info(f"Connect to the database for {self.db_name}") + self.logger.info(f'Connect to the database for "{self.db_name}"') self.connection = self.engine.connect() def disconnect(self) -> None: - self.logger.info(f"Disconnect to the database for {self.db_name}") + self.logger.info(f'Disconnect to the database for "{self.db_name}"') if not self.connection: raise RuntimeError("Cannot close database connection - already closed") self.connection.close() def create_db(self) -> None: """Ensure that the database exists with given schema.""" - self.logger.info(f"Create database {self.db_name}") + self.logger.info(f'Create database "{self.db_name}"') Base.metadata.create_all(self.engine) def drop(self) -> None: """WARNING: Drops the entire database.""" - self.logger.warning(f"Drop database {self.db_name}") + self.logger.warning(f'Drop database "{self.db_name}"') if not self.is_connected: self.connect() Base.metadata.drop_all(self.engine) From 4fe5c5cab08dc26df8586b1df64e43a381295ba7 Mon Sep 17 00:00:00 2001 From: Eduard Kaverinskyi Date: Sat, 18 Jan 2025 18:10:34 +0100 Subject: [PATCH 05/16] whois/worker.py: fix outdated settings Signed-off-by: Eduard Kaverinskyi --- whois/worker.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/whois/worker.py b/whois/worker.py index d8d1a9e..383a013 100644 --- a/whois/worker.py +++ b/whois/worker.py @@ -4,7 +4,7 @@ from whois.data.db.database import Database from whois.data.repository.device_repository import DeviceRepository, Device from whois.mikrotik import fetch_leases -from whois.settings import production +from whois.settings.production import mikrotik_settings logger = logging.getLogger("mikrotik-worker") database = Database() @@ -12,7 +12,7 @@ def update_devices() -> int: leases = fetch_leases( - production.MIKROTIK_URL, production.MIKROTIK_USER, production.MIKROTIK_PASS + mikrotik_settings.MIKROTIK_URL, mikrotik_settings.MIKROTIK_USER, mikrotik_settings.MIKROTIK_PASS ) for lease in leases: @@ -27,7 +27,7 @@ def update_devices() -> int: def run_worker(): if not all( - [production.MIKROTIK_URL, production.MIKROTIK_USER, production.MIKROTIK_PASS] + [mikrotik_settings.MIKROTIK_URL, mikrotik_settings.MIKROTIK_USER, mikrotik_settings.MIKROTIK_PASS] ): raise ValueError("Mikrotik settings not set") @@ -39,7 +39,7 @@ def run_worker(): except Exception: logger.exception("Could not update device information") - time.sleep(production.worker_frequency_s) + time.sleep(mikrotik_settings.WORKER_FREQUENCY_S) if __name__ == "__main__": From 938190b72246e665eb184b5386f919a19779ffe7 Mon Sep 17 00:00:00 2001 From: Eduard Kaverinskyi Date: Sat, 18 Jan 2025 18:18:13 +0100 Subject: [PATCH 06/16] db/mapper/device_mapper.py: fix device.username -> device.hostname Signed-off-by: Eduard Kaverinskyi --- whois/data/db/mapper/device_mapper.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/whois/data/db/mapper/device_mapper.py b/whois/data/db/mapper/device_mapper.py index 49e399b..cb016f6 100644 --- a/whois/data/db/mapper/device_mapper.py +++ b/whois/data/db/mapper/device_mapper.py @@ -5,7 +5,7 @@ def device_to_devicetable_mapper(device: Device) -> DeviceTable: return DeviceTable( mac_address=device.mac_address, - hostname=device.username, + hostname=device.hostname, last_seen=device.last_seen, owner=device.owner, flags=device.flags, @@ -15,7 +15,7 @@ def device_to_devicetable_mapper(device: Device) -> DeviceTable: def devicetable_to_device_mapper(device: DeviceTable) -> Device: return Device( mac_address=device.mac_address, - hostname=device.username, + hostname=device.hostname, last_seen=device.last_seen, owner=device.owner, flags=device.flags, From 6bbb322b92077873a36a7fbf77bfa7d5ab4a087b Mon Sep 17 00:00:00 2001 From: Eduard Kaverinskyi Date: Sat, 18 Jan 2025 18:25:52 +0100 Subject: [PATCH 07/16] worker.py: fix missing params for device object Signed-off-by: Eduard Kaverinskyi --- whois/worker.py | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/whois/worker.py b/whois/worker.py index 383a013..98b16e9 100644 --- a/whois/worker.py +++ b/whois/worker.py @@ -3,6 +3,7 @@ from whois.data.db.database import Database from whois.data.repository.device_repository import DeviceRepository, Device +from whois.data.type.bitfield import BitField from whois.mikrotik import fetch_leases from whois.settings.production import mikrotik_settings @@ -16,7 +17,7 @@ def update_devices() -> int: ) for lease in leases: - device = Device(lease.mac_address, lease.host_name, lease.last_seen) + device = Device(lease.mac_address, lease.host_name, lease.last_seen, lease.client_id, BitField()) #TODO figure out how to pass flags if device_repository.get_by_mac_address(lease.mac_address): device_repository.update(device) else: From fe60fe8e1b3c2a4ca9c0869c370b22babf8f702c Mon Sep 17 00:00:00 2001 From: Eduard Kaverinskyi Date: Sat, 18 Jan 2025 18:30:43 +0100 Subject: [PATCH 08/16] whois/app.py: fix passing owner id's instead of entities Signed-off-by: Eduard Kaverinskyi --- whois/app.py | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/whois/app.py b/whois/app.py index b3e6fb9..2f07fb4 100644 --- a/whois/app.py +++ b/whois/app.py @@ -210,7 +210,10 @@ def now_at_space(self): recent = self.device_repository.get_recent( timedelta(**self.app_settings.RECENT_TIME) ) - users = self.helpers.filter_hidden(self.helpers.owners_from_devices(recent)) + owners = self.helpers.owners_from_devices(recent) + users = self.helpers.filter_hidden( + [self.user_repository.get_by_id(owner) for owner in owners] + ) data = { "users": sorted(map(str, self.helpers.filter_anon_names(users))), From 0cb4edc499a3b3d6352790bb69c3c328b8d656fd Mon Sep 17 00:00:00 2001 From: Eduard Kaverinskyi Date: Sat, 18 Jan 2025 18:39:24 +0100 Subject: [PATCH 09/16] device_repository.py: fix map for get_by_mac_address Signed-off-by: Eduard Kaverinskyi --- whois/data/repository/device_repository.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/whois/data/repository/device_repository.py b/whois/data/repository/device_repository.py index 8b993aa..6d313cf 100644 --- a/whois/data/repository/device_repository.py +++ b/whois/data/repository/device_repository.py @@ -42,7 +42,7 @@ def get_by_mac_address(self, mac_address: str) -> Device: .where(DeviceTable.mac_address == mac_address) .one() ) - return map(devicetable_to_device_mapper, device_orm) + return next(map(devicetable_to_device_mapper, [device_orm])) def get_all(self) -> List[Device]: with Session(self.database.engine) as session: From a003d50ba3ecc233d9dc757f6bbf42aaea35c11a Mon Sep 17 00:00:00 2001 From: Eduard Kaverinskyi Date: Sat, 18 Jan 2025 18:47:46 +0100 Subject: [PATCH 10/16] entity/device.py: implement is_hidden for Device Signed-off-by: Eduard Kaverinskyi --- whois/entity/device.py | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/whois/entity/device.py b/whois/entity/device.py index 69b32d1..ca560d0 100644 --- a/whois/entity/device.py +++ b/whois/entity/device.py @@ -20,3 +20,7 @@ class Device: last_seen: IsoDateTimeField owner: int flags: BitField + + @property + def is_hidden(self) -> bool: + return self.flags.has_flag(DeviceFlags.is_hidden.value) \ No newline at end of file From 99673a8b100802b87f48d62771aaa673b94edc37 Mon Sep 17 00:00:00 2001 From: Eduard Kaverinskyi Date: Sat, 18 Jan 2025 18:58:21 +0100 Subject: [PATCH 11/16] device_mapper.py: fix passing non-python value to sqlite db Signed-off-by: Eduard Kaverinskyi --- whois/data/db/mapper/device_mapper.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/whois/data/db/mapper/device_mapper.py b/whois/data/db/mapper/device_mapper.py index cb016f6..cee0554 100644 --- a/whois/data/db/mapper/device_mapper.py +++ b/whois/data/db/mapper/device_mapper.py @@ -6,7 +6,7 @@ def device_to_devicetable_mapper(device: Device) -> DeviceTable: return DeviceTable( mac_address=device.mac_address, hostname=device.hostname, - last_seen=device.last_seen, + last_seen=device.last_seen.python_value, owner=device.owner, flags=device.flags, ) From 2899372bd04d9cfe60a479dfb85a9663c14592ce Mon Sep 17 00:00:00 2001 From: Eduard Kaverinskyi Date: Sat, 18 Jan 2025 19:03:46 +0100 Subject: [PATCH 12/16] Revert "device_mapper.py: fix passing non-python value to sqlite db" This reverts commit 99673a8b100802b87f48d62771aaa673b94edc37. --- whois/data/db/mapper/device_mapper.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/whois/data/db/mapper/device_mapper.py b/whois/data/db/mapper/device_mapper.py index cee0554..cb016f6 100644 --- a/whois/data/db/mapper/device_mapper.py +++ b/whois/data/db/mapper/device_mapper.py @@ -6,7 +6,7 @@ def device_to_devicetable_mapper(device: Device) -> DeviceTable: return DeviceTable( mac_address=device.mac_address, hostname=device.hostname, - last_seen=device.last_seen.python_value, + last_seen=device.last_seen, owner=device.owner, flags=device.flags, ) From 4312e87d3dd288a922ac12600d9d266c26108697 Mon Sep 17 00:00:00 2001 From: Eduard Kaverinskyi Date: Sat, 18 Jan 2025 19:05:51 +0100 Subject: [PATCH 13/16] device_repository.py: fix passing non-python datetime on update() --- whois/data/repository/device_repository.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/whois/data/repository/device_repository.py b/whois/data/repository/device_repository.py index 6d313cf..07bef9c 100644 --- a/whois/data/repository/device_repository.py +++ b/whois/data/repository/device_repository.py @@ -30,7 +30,7 @@ def update(self, device: Device) -> None: .one() ) device_orm.hostname = device.hostname - device_orm.last_seen = device.last_seen + device_orm.last_seen = device.last_seen.python_value device_orm.owner = device.owner device_orm.flags = device.flags session.commit() From 562934289fbefa1b80f0122cc49ad351664c2098 Mon Sep 17 00:00:00 2001 From: Eduard Kaverinskyi Date: Mon, 3 Feb 2025 18:24:01 +0100 Subject: [PATCH 14/16] Refine logging Signed-off-by: Eduard Kaverinskyi --- .gitignore | 5 +- env.sh | 1 + helpers/logger.py | 51 +++++++++++++ tests/test_integration.py | 11 +-- whois/app.py | 84 +++++++++++++--------- whois/data/db/database.py | 19 +++-- whois/data/repository/device_repository.py | 11 ++- whois/data/repository/user_repository.py | 9 ++- whois/data/table/device.py | 2 +- whois/entity/device.py | 2 +- whois/helpers.py | 5 +- whois/web.py | 4 +- whois/worker.py | 11 ++- 13 files changed, 146 insertions(+), 69 deletions(-) create mode 100644 helpers/logger.py diff --git a/.gitignore b/.gitignore index f6f8172..2b4eee5 100644 --- a/.gitignore +++ b/.gitignore @@ -107,4 +107,7 @@ venv.bak/ *.db # Logs -*.log \ No newline at end of file +*.log + +# Database files +*.sqlite \ No newline at end of file diff --git a/env.sh b/env.sh index a1b9c50..e10e380 100644 --- a/env.sh +++ b/env.sh @@ -1,5 +1,6 @@ export APP_DB_URL="postgresql://whohacks:S3cret@localhost:5432/whohacks" export OAUTH_OPENID="http://sso.hsp.sh/auth/realms/hsp/.well-known/openid-configuration" export OAUTH_CLIENT_ID="fake-development-client-id" +export LOGLEVEL="DEBUG" # DEBUG | INFO | WARNING | ERROR env | grep APP_ > .env env | grep OUATH_ > .env \ No newline at end of file diff --git a/helpers/logger.py b/helpers/logger.py new file mode 100644 index 0000000..b679b81 --- /dev/null +++ b/helpers/logger.py @@ -0,0 +1,51 @@ +import logging +import os + +loggers = {} + +def get_loglevel(loglevel: str): + match loglevel: + case "DEBUG": + loglevel = logging.DEBUG + case "INFO": + loglevel = logging.INFO + case "WARNING": + loglevel = logging.WARNING + case "ERROR": + loglevel = logging.ERROR + case "CRITICAL": + loglevel = logging.CRITICAL + case _: + loglevel = logging.INFO + + return loglevel + + +def init_logger(name: str) -> logging.Logger: + if loggers.get(name): + return loggers[name] + + logger = logging.getLogger(name) + loglevel = get_loglevel(os.environ.get("LOGLEVEL")) + + formatter = logging.Formatter( + fmt=f"({name}) %(asctime)s %(module)s %(levelname)s: %(message)s", + datefmt="%m/%d/%Y %I:%M:%S %p", + ) + + for handler in logger.handlers: + logger.removeHandler(handler) + + stream_handler = logging.StreamHandler() + stream_handler.setFormatter(formatter) + file_handler = logging.FileHandler(f"{name}.log") + file_handler.setFormatter(formatter) + + logger.addHandler(stream_handler) + logger.addHandler(file_handler) + + logger.setLevel(loglevel) + + loggers[name] = logger + + return logger diff --git a/tests/test_integration.py b/tests/test_integration.py index 45f5445..234922e 100644 --- a/tests/test_integration.py +++ b/tests/test_integration.py @@ -4,24 +4,19 @@ from whois.app import WhohacksApp from whois.data.db.database import Database from whois.settings.testing import app_settings, mikrotik_settings +from helpers.logger import init_logger class ApiTestCase(TestCase): def setUp(self): - self.logger = logging.getLogger(__name__) - logging.basicConfig( - format="%(asctime)s %(module)s %(levelname)s: %(message)s", - datefmt="%m/%d/%Y %I:%M:%S %p", - level=logging.DEBUG, - force=True, - ) + self.logger = init_logger(__name__) self.logger.addHandler(logging.FileHandler(f"{__name__}.log")) self.db = Database("sqlite:///whohacks.test.sqlite") self.db.drop() self.db.create_db() - self.whois = WhohacksApp(app_settings, mikrotik_settings, self.db, self.logger) + self.whois = WhohacksApp(app_settings, mikrotik_settings, self.db) self.app = self.whois.app.test_client() self.app.testing = True diff --git a/whois/app.py b/whois/app.py index 2f07fb4..b4abecc 100644 --- a/whois/app.py +++ b/whois/app.py @@ -30,6 +30,7 @@ from whois.entity.user import User, UserFlags from whois.helpers import Helpers from whois.settings.settings_template import AppSettings, MikrotikSettings +from helpers.logger import init_logger class WhohacksApp: @@ -39,10 +40,9 @@ def __init__( app_settings: AppSettings, mikrotik_settings: MikrotikSettings, database: Database, - logger: Logger, ): - self.logger = logger - self.logger.debug("Initializing WhohacksApp...") + self.logger = init_logger("WhohacksApp") + self.logger.info("Initializing WhohacksApp...") self.app = Flask(__name__) self.cors = CORS(self.app, resources={r"/api/*": {"origins": "*"}}) @@ -66,7 +66,7 @@ def __init__( self.add_template_filters() self.register_routes() - self.logger.debug("Initialized WhohacksApp") + self.logger.info("Initialized WhohacksApp") self.common_vars_tpl = {"app": self.app.config.get_namespace("APP_")} @@ -78,6 +78,12 @@ def __init__( client_kwargs={"scope": "openid profile email"}, ) + def _log_endpoint(self, endpoint: str, details: str = None) -> None: + if details: + self.logger.debug(f'Called "{endpoint}", ' + details) + else: + self.logger.debug(f'Called "{endpoint}"') + def add_rules(self) -> None: self.login_manager.user_loader(self.load_user) self.app.before_request = self.before_request @@ -116,6 +122,7 @@ def register_routes(self) -> None: # Rules for Flask App def load_user(self, user_id): + self.logger.debug(f'Load user with ID: "{user_id}"') try: return self.user_repository.get_by_id(user_id) except NoResultFound as exc: @@ -123,7 +130,7 @@ def load_user(self, user_id): return None def before_request(self): - self.app.logger.info("connecting to db") + self.logger.debug("Preparing for request") self.database.connect() if request.headers.getlist("X-Forwarded-For"): @@ -141,19 +148,14 @@ def before_request(self): flash("Outside local network, some functions forbidden!", "outside-warning") def after_request(self, error): - if self.database.is_connected: - self.app.logger.info("Closing the database connection") - self.database.disconnect() - else: - self.app.logger.info("Database connection was already closed") - + self.database.disconnect() if error: - self.app.logger.error(error) + self.logger.error(error) # Routes for Flask App def index(self): """Serve list of people in hs, show panel for logged users""" - self.logger.debug("Called '/'") + self._log_endpoint("/") recent = self.device_repository.get_recent( timedelta(**self.app_settings.RECENT_TIME) ) @@ -172,7 +174,7 @@ def index(self): @login_required def devices(self): - self.logger.debug("Called '/devices'") + self._log_endpoint("/devices") recent = self.device_repository.get_recent( timedelta(**self.app_settings.RECENT_TIME) ) @@ -200,7 +202,8 @@ def now_at_space(self): used by other services in HS, requests should be from hsp.sh domain or from HSWAN """ - self.logger.debug("Called '/api/now'") + self._log_endpoint("/api/now") + self.logger.debug(f'Recieved arguments: "{request.args}"') period = {**self.app_settings.RECENT_TIME} for key in ["days", "hours", "minutes"]: @@ -221,19 +224,20 @@ def now_at_space(self): "unknown_devices": len(self.helpers.unclaimed_devices(recent)), } - self.logger.info("sending request for /api/now {}".format(data)) + self.logger.info("Sending request for /api/now {}".format(data)) return jsonify(data) def set_device_flags(self, device, new_flags): + self.logger.debug(f"Update device flags: {device=}, {new_flags=}") if device.owner is not None and device.owner.get_id() != current_user.get_id(): - self.logger.error("no permission for {}".format(current_user.username)) + self.logger.error("No permission for {}".format(current_user.username)) flash("No permission!".format(device.mac_address), "error") return device.is_hidden = "hidden" in new_flags device.is_esp = "esp" in new_flags device.is_infrastructure = "infrastructure" in new_flags - print(device.flags) + self.logger.debug(f"New device_flags={device.flags}") device.save() self.logger.info( "{} changed {} flags to {}".format( @@ -244,7 +248,7 @@ def set_device_flags(self, device, new_flags): def device_view(self, mac_address): """Get info about device, claim device, release device""" - self.logger.debug("Called '/device'") + self._log_endpoint("/device") try: device = self.device_repository.get_by_mac_address(mac_address) except NoResultFound as exc: @@ -265,8 +269,9 @@ def device_view(self, mac_address): return render_template("device.html", device=device, **self.common_vars_tpl) def claim_device(self, device): + self.logger.debug(f"Claim device: {device.__repr__()}") if device.owner is not None: - self.logger.error("no permission for {}".format(current_user.username)) + self.logger.error("No permission for {}".format(current_user.username)) flash("No permission!".format(device.mac_address), "error") return device.owner = current_user.get_id() @@ -277,8 +282,9 @@ def claim_device(self, device): flash("Claimed {}!".format(device.mac_address), "success") def unclaim_device(self, device): + self.logger.debug(f"Unclaim device: {device.__repr__()}") if device.owner is not None and device.owner.get_id() != current_user.get_id(): - self.logger.error("no permission for {}".format(current_user.username)) + self.logger.error("No permission for {}".format(current_user.username)) flash("No permission!".format(device.mac_address), "error") return device.owner = None @@ -319,10 +325,10 @@ def register_form(self): def login(self): """Login using query to DB or SSO""" - self.logger.debug("Called '/login'") + self._log_endpoint("/login") if current_user.is_authenticated: - self.logger.error("Shouldn't login when auth") + self.logger.info(f"User {current_user} is already authenticated") flash("You are already logged in", "error") return redirect(url_for("devices")) @@ -334,14 +340,21 @@ def login(self): user = None if user: + self.logger.debug(f"User found: {user}") if user.is_sso and self.app_settings.OIDC_ENABLED: - # User created via sso -> redirect to sso login - self.logger.info("Redirect to SSO user: {}".format(user.username)) + self.logger.info( + f"User {user} is an SSO user. Redirecting to SSO login" + ) return redirect(url_for("login_oauth")) elif user.auth(request.form["password"]): # User password hash match -> login user successfully - login_user(user) - self.logger.info("logged in: {}".format(user.username)) + self.logger.info(f"User {user} is a regular user. Attempt login") + login_success = login_user(user) + if login_success: + self.logger.info(f"User {user} was successfully authenticated") + else: + self.logger.info(f"User {user} was NOT authenticated") + else: pass @@ -354,7 +367,9 @@ def login(self): ) return redirect(url_for("devices")) else: - self.logger.info("failed log in: {}".format(request.form["username"])) + self.logger.info( + f"Failed to log in: username={request.form["username"]}" + ) flash("Invalid credentials", "error") return render_template( @@ -364,12 +379,12 @@ def login(self): ) def login_oauth(self): - self.logger.debug("Called '/login/oauth'") + self._log_endpoint("/login/oauth") redirect_uri = url_for("callback", _external=True) return self.oauth.sso.authorize_redirect(redirect_uri) def callback(self): - self.logger.debug("Called '/login/callback'") + self._log_endpoint("/login/callback") token = self.oauth.sso.authorize_access_token() user_info = self.oauth.sso.parse_id_token(token) if user_info: @@ -402,16 +417,15 @@ def callback(self): return redirect(url_for("login")) def logout(self): - self.logger.debug("Called '/logout'") username = current_user.username + self._log_endpoint("/logout", f"{username=}") logout_user() self.app.logger.info("logged out: {}".format(username)) flash("Logged out.", "info") return redirect(url_for("index")) def profile_edit(self): - # TODO: logging - self.logger.debug("Called '/profile'") + self._log_endpoint("/profile") if request.method == "POST": if current_user.auth(request.values.get("password", None)) is True: try: @@ -459,8 +473,10 @@ def register(self, username, password, display_name=None): :param display_name: displayed username :return: user instance """ + self.logger.debug(f"Registering user: {username}") user = User(username=username, display_name=display_name) user.password = password + self.logger.debug(f"Final user: {user.__repr__()}") self.user_repository.insert(user) return user @@ -471,6 +487,8 @@ def register_from_sso(self, username, display_name=None): :param display_name: displayed username :return: user instance """ + self.logger.debug(f"Registering user (SSO): {username}") user = User(username=username, display_name=display_name) + self.logger.debug(f"Final user: {user.__repr__()}") self.user_repository.insert(user) return user diff --git a/whois/data/db/database.py b/whois/data/db/database.py index e3359fe..a1a1c09 100644 --- a/whois/data/db/database.py +++ b/whois/data/db/database.py @@ -6,6 +6,7 @@ from whois.data.db.base import Base from whois.data.table.device import DeviceTable from whois.data.table.user import UserTable +from helpers.logger import init_logger class Database: @@ -16,15 +17,10 @@ def __init__(self, db_url: str = None): db_url = os.environ.get("APP_DB_URL", "sqlite:///whohacks.sqlite") self.db_name = db_url.split("/")[-1] - self.logger = logging.getLogger(f"db-{self.db_name}") - logging.basicConfig( - format="%(asctime)s %(module)s %(levelname)s: %(message)s", - datefmt="%m/%d/%Y %I:%M:%S %p", - level=logging.DEBUG, - force=True, - ) + self.logger = init_logger(f"db-{self.db_name}") - self.logger.debug(f'Creating engine for "{db_url}"') + self.logger.info(f'Creating engine for "{db_url}"') + self.logger.debug(f'Database URL: "{db_url}"') self.engine = db.create_engine(db_url) self.metadata = db.MetaData() self.connection = None @@ -33,18 +29,19 @@ def __init__(self, db_url: str = None): self.device_table = DeviceTable() self.create_db() + @property def is_connected(self) -> bool: return self.connection is not None def connect(self) -> None: - self.logger.info(f'Connect to the database for "{self.db_name}"') + self.logger.debug("Connect to the database") self.connection = self.engine.connect() def disconnect(self) -> None: - self.logger.info(f'Disconnect to the database for "{self.db_name}"') + self.logger.debug("Close database connection") if not self.connection: - raise RuntimeError("Cannot close database connection - already closed") + self.logger.debug("Cannot close database connection - already closed") self.connection.close() def create_db(self) -> None: diff --git a/whois/data/repository/device_repository.py b/whois/data/repository/device_repository.py index 07bef9c..1f22ff0 100644 --- a/whois/data/repository/device_repository.py +++ b/whois/data/repository/device_repository.py @@ -11,18 +11,23 @@ from whois.data.table.device import DeviceTable from whois.entity.device import Device +from helpers.logger import init_logger + class DeviceRepository: def __init__(self, database: Database) -> None: self.database = database - + self.logger = init_logger("DeviceRepository") + def insert(self, device: Device) -> None: + self.logger.debug(f'Insert device: "{device.__repr__()}"') with Session(self.database.engine) as session: session.add(device_to_devicetable_mapper(device)) session.commit() def update(self, device: Device) -> None: + self.logger.debug(f'Update device: "{device.__repr__()}"') with Session(self.database.engine) as session: device_orm = ( session.query(DeviceTable) @@ -36,6 +41,7 @@ def update(self, device: Device) -> None: session.commit() def get_by_mac_address(self, mac_address: str) -> Device: + self.logger.debug(f'Seach device by mac address: "{mac_address}"') with Session(self.database.engine) as session: device_orm = ( session.query(DeviceTable) @@ -45,11 +51,13 @@ def get_by_mac_address(self, mac_address: str) -> Device: return next(map(devicetable_to_device_mapper, [device_orm])) def get_all(self) -> List[Device]: + self.logger.debug('Get all devices') with Session(self.database.engine) as session: devices_orm = session.query(DeviceTable).all() return list(map(devicetable_to_device_mapper, devices_orm)) def get_by_user_id(self, user_id: int) -> List[Device]: + self.logger.debug(f'Seach device by user ID: "{user_id}"') with Session(self.database.engine) as session: devices_orm = ( session.query(DeviceTable).where(DeviceTable.owner == user_id).all() @@ -60,6 +68,7 @@ def get_by_user_id(self, user_id: int) -> List[Device]: return list() def get_recent(self, delta: timedelta) -> List[Device]: + self.logger.debug(f'Get recent devices with delta="{delta}"') with Session(self.database.engine) as session: recent_time = datetime.now(timezone.utc) - delta devices_orm = ( diff --git a/whois/data/repository/user_repository.py b/whois/data/repository/user_repository.py index dad7981..2ac8c5a 100644 --- a/whois/data/repository/user_repository.py +++ b/whois/data/repository/user_repository.py @@ -9,18 +9,22 @@ ) from whois.data.table.user import UserTable from whois.entity.user import User +from helpers.logger import init_logger class UserRepository: def __init__(self, database: Database) -> None: self.database = database - + self.logger = init_logger("UserRepository") + def insert(self, user: User) -> None: + self.logger.debug(f'Insert user: "{user.__repr__()}"') with Session(self.database.engine) as session: session.add(user_to_usertable_mapper(user)) session.commit() def update(self, user: User) -> None: + self.logger.debug(f'Update user: "{user.__repr__()}"') with Session(self.database.engine) as session: user_orm = session.query(UserTable).where(UserTable.id == user.id).one() user_orm.username = user.username @@ -30,11 +34,13 @@ def update(self, user: User) -> None: session.commit() def get_all(self) -> List[User]: + self.logger.debug("Get all users") with Session(self.database.engine) as session: users_orm = session.query(UserTable).all() return list(map(usertable_to_user_mapper, users_orm)) def get_by_username(self, username: str) -> User: + self.logger.debug(f'Get user by username: "{username}"') with Session(self.database.engine) as session: user_orm = ( session.query(UserTable).where(UserTable.username == username).one() @@ -43,6 +49,7 @@ def get_by_username(self, username: str) -> User: return usertable_to_user_mapper(user_orm) def get_by_id(self, id: int) -> User: + self.logger.debug(f'Get user by ID: "{id}"') with Session(self.database.engine) as session: user_orm = session.query(UserTable).where(UserTable.id == id).one() diff --git a/whois/data/table/device.py b/whois/data/table/device.py index 1602e6e..e847d6c 100644 --- a/whois/data/table/device.py +++ b/whois/data/table/device.py @@ -26,4 +26,4 @@ class DeviceTable(Base): flags = Column(BitField, nullable=True) def __str__(self) -> str: - return str(self.mac_address) + return str(self.mac_address) \ No newline at end of file diff --git a/whois/entity/device.py b/whois/entity/device.py index ca560d0..17b0853 100644 --- a/whois/entity/device.py +++ b/whois/entity/device.py @@ -23,4 +23,4 @@ class Device: @property def is_hidden(self) -> bool: - return self.flags.has_flag(DeviceFlags.is_hidden.value) \ No newline at end of file + return self.flags.has_flag(DeviceFlags.is_hidden.value) diff --git a/whois/helpers.py b/whois/helpers.py index 5101059..656c5db 100644 --- a/whois/helpers.py +++ b/whois/helpers.py @@ -8,10 +8,9 @@ from whois.entity.device import Device from whois.settings.settings_template import AppSettings +from helpers.logger import init_logger -logging.basicConfig(level=logging.INFO) -logger = logging.getLogger(__name__) - +logger = init_logger(__name__) class Helpers: diff --git a/whois/web.py b/whois/web.py index c6c16d6..5b19c96 100644 --- a/whois/web.py +++ b/whois/web.py @@ -5,8 +5,6 @@ from whois.settings.production import app_settings, mikrotik_settings database = Database() -logging.basicConfig(level=logging.INFO) -logger = logging.getLogger(__name__) -whois = WhohacksApp(app_settings, mikrotik_settings, database, logger) +whois = WhohacksApp(app_settings, mikrotik_settings, database) app = whois.app diff --git a/whois/worker.py b/whois/worker.py index 98b16e9..a26acfb 100644 --- a/whois/worker.py +++ b/whois/worker.py @@ -6,18 +6,22 @@ from whois.data.type.bitfield import BitField from whois.mikrotik import fetch_leases from whois.settings.production import mikrotik_settings +from helpers.logger import init_logger -logger = logging.getLogger("mikrotik-worker") +logger = init_logger("mikrotik-worker") database = Database() device_repository = DeviceRepository(database) def update_devices() -> int: + logger.info("Updating devices") leases = fetch_leases( mikrotik_settings.MIKROTIK_URL, mikrotik_settings.MIKROTIK_USER, mikrotik_settings.MIKROTIK_PASS ) + logger.debug(f"Fetched leases: {leases}") for lease in leases: device = Device(lease.mac_address, lease.host_name, lease.last_seen, lease.client_id, BitField()) #TODO figure out how to pass flags + logger.debug(f"Processing Device: {device.__repr__()}") if device_repository.get_by_mac_address(lease.mac_address): device_repository.update(device) else: @@ -44,9 +48,4 @@ def run_worker(): if __name__ == "__main__": - logging.basicConfig( - format="[%(asctime)s] %(name)s [%(levelname)s]: %(msg)s", - level=logging.INFO, - datefmt="%Y-%m-%d %H:%M:%S", - ) run_worker() From a21f3fa95834c9bb7db319a55de3c9f65467600f Mon Sep 17 00:00:00 2001 From: Eduard Kaverinskyi Date: Mon, 3 Feb 2025 18:26:39 +0100 Subject: [PATCH 15/16] Format code Signed-off-by: Eduard Kaverinskyi --- helpers/logger.py | 9 +++++---- tests/test_integration.py | 2 +- whois/app.py | 23 +++++----------------- whois/data/db/database.py | 3 +-- whois/data/repository/device_repository.py | 13 +++++------- whois/data/repository/user_repository.py | 10 ++++------ whois/data/table/device.py | 2 +- whois/helpers.py | 3 ++- whois/settings/production.py | 3 ++- whois/worker.py | 23 +++++++++++++++++----- 10 files changed, 44 insertions(+), 47 deletions(-) diff --git a/helpers/logger.py b/helpers/logger.py index b679b81..a9e8c6e 100644 --- a/helpers/logger.py +++ b/helpers/logger.py @@ -3,6 +3,7 @@ loggers = {} + def get_loglevel(loglevel: str): match loglevel: case "DEBUG": @@ -24,7 +25,7 @@ def get_loglevel(loglevel: str): def init_logger(name: str) -> logging.Logger: if loggers.get(name): return loggers[name] - + logger = logging.getLogger(name) loglevel = get_loglevel(os.environ.get("LOGLEVEL")) @@ -32,10 +33,10 @@ def init_logger(name: str) -> logging.Logger: fmt=f"({name}) %(asctime)s %(module)s %(levelname)s: %(message)s", datefmt="%m/%d/%Y %I:%M:%S %p", ) - + for handler in logger.handlers: logger.removeHandler(handler) - + stream_handler = logging.StreamHandler() stream_handler.setFormatter(formatter) file_handler = logging.FileHandler(f"{name}.log") @@ -45,7 +46,7 @@ def init_logger(name: str) -> logging.Logger: logger.addHandler(file_handler) logger.setLevel(loglevel) - + loggers[name] = logger return logger diff --git a/tests/test_integration.py b/tests/test_integration.py index 234922e..1fe4002 100644 --- a/tests/test_integration.py +++ b/tests/test_integration.py @@ -1,10 +1,10 @@ import logging from unittest import TestCase +from helpers.logger import init_logger from whois.app import WhohacksApp from whois.data.db.database import Database from whois.settings.testing import app_settings, mikrotik_settings -from helpers.logger import init_logger class ApiTestCase(TestCase): diff --git a/whois/app.py b/whois/app.py index b4abecc..a0f3c4d 100644 --- a/whois/app.py +++ b/whois/app.py @@ -4,33 +4,20 @@ from logging import Logger from authlib.integrations.flask_client import OAuth -from flask import ( - Flask, - abort, - flash, - jsonify, - redirect, - render_template, - request, - url_for, -) +from flask import (Flask, abort, flash, jsonify, redirect, render_template, + request, url_for) from flask_cors import CORS -from flask_login import ( - LoginManager, - current_user, - login_required, - login_user, - logout_user, -) +from flask_login import (LoginManager, current_user, login_required, + login_user, logout_user) from sqlalchemy.orm.exc import NoResultFound +from helpers.logger import init_logger from whois.data.db.database import Database from whois.data.repository.device_repository import DeviceRepository from whois.data.repository.user_repository import UserRepository from whois.entity.user import User, UserFlags from whois.helpers import Helpers from whois.settings.settings_template import AppSettings, MikrotikSettings -from helpers.logger import init_logger class WhohacksApp: diff --git a/whois/data/db/database.py b/whois/data/db/database.py index a1a1c09..daab1ce 100644 --- a/whois/data/db/database.py +++ b/whois/data/db/database.py @@ -3,10 +3,10 @@ import sqlalchemy as db +from helpers.logger import init_logger from whois.data.db.base import Base from whois.data.table.device import DeviceTable from whois.data.table.user import UserTable -from helpers.logger import init_logger class Database: @@ -29,7 +29,6 @@ def __init__(self, db_url: str = None): self.device_table = DeviceTable() self.create_db() - @property def is_connected(self) -> bool: return self.connection is not None diff --git a/whois/data/repository/device_repository.py b/whois/data/repository/device_repository.py index 1f22ff0..99a91e5 100644 --- a/whois/data/repository/device_repository.py +++ b/whois/data/repository/device_repository.py @@ -3,23 +3,20 @@ from sqlalchemy.orm import Session +from helpers.logger import init_logger from whois.data.db.database import Database -from whois.data.db.mapper.device_mapper import ( - device_to_devicetable_mapper, - devicetable_to_device_mapper, -) +from whois.data.db.mapper.device_mapper import (device_to_devicetable_mapper, + devicetable_to_device_mapper) from whois.data.table.device import DeviceTable from whois.entity.device import Device -from helpers.logger import init_logger - class DeviceRepository: def __init__(self, database: Database) -> None: self.database = database self.logger = init_logger("DeviceRepository") - + def insert(self, device: Device) -> None: self.logger.debug(f'Insert device: "{device.__repr__()}"') with Session(self.database.engine) as session: @@ -51,7 +48,7 @@ def get_by_mac_address(self, mac_address: str) -> Device: return next(map(devicetable_to_device_mapper, [device_orm])) def get_all(self) -> List[Device]: - self.logger.debug('Get all devices') + self.logger.debug("Get all devices") with Session(self.database.engine) as session: devices_orm = session.query(DeviceTable).all() return list(map(devicetable_to_device_mapper, devices_orm)) diff --git a/whois/data/repository/user_repository.py b/whois/data/repository/user_repository.py index 2ac8c5a..ecba81f 100644 --- a/whois/data/repository/user_repository.py +++ b/whois/data/repository/user_repository.py @@ -2,21 +2,19 @@ from sqlalchemy.orm import Session +from helpers.logger import init_logger from whois.data.db.database import Database -from whois.data.db.mapper.user_mapper import ( - user_to_usertable_mapper, - usertable_to_user_mapper, -) +from whois.data.db.mapper.user_mapper import (user_to_usertable_mapper, + usertable_to_user_mapper) from whois.data.table.user import UserTable from whois.entity.user import User -from helpers.logger import init_logger class UserRepository: def __init__(self, database: Database) -> None: self.database = database self.logger = init_logger("UserRepository") - + def insert(self, user: User) -> None: self.logger.debug(f'Insert user: "{user.__repr__()}"') with Session(self.database.engine) as session: diff --git a/whois/data/table/device.py b/whois/data/table/device.py index e847d6c..1602e6e 100644 --- a/whois/data/table/device.py +++ b/whois/data/table/device.py @@ -26,4 +26,4 @@ class DeviceTable(Base): flags = Column(BitField, nullable=True) def __str__(self) -> str: - return str(self.mac_address) \ No newline at end of file + return str(self.mac_address) diff --git a/whois/helpers.py b/whois/helpers.py index 656c5db..76f051c 100644 --- a/whois/helpers.py +++ b/whois/helpers.py @@ -6,12 +6,13 @@ from flask import abort, request +from helpers.logger import init_logger from whois.entity.device import Device from whois.settings.settings_template import AppSettings -from helpers.logger import init_logger logger = init_logger(__name__) + class Helpers: def __init__(self, app_settings: AppSettings): diff --git a/whois/settings/production.py b/whois/settings/production.py index 637b1fd..0d6986e 100644 --- a/whois/settings/production.py +++ b/whois/settings/production.py @@ -6,7 +6,8 @@ try: from importlib.metadata import version - _version = version('whois') + + _version = version("whois") except Exception: _version = "unknown" diff --git a/whois/worker.py b/whois/worker.py index a26acfb..429ff51 100644 --- a/whois/worker.py +++ b/whois/worker.py @@ -1,26 +1,35 @@ import logging import time +from helpers.logger import init_logger from whois.data.db.database import Database -from whois.data.repository.device_repository import DeviceRepository, Device +from whois.data.repository.device_repository import Device, DeviceRepository from whois.data.type.bitfield import BitField from whois.mikrotik import fetch_leases from whois.settings.production import mikrotik_settings -from helpers.logger import init_logger logger = init_logger("mikrotik-worker") database = Database() device_repository = DeviceRepository(database) + def update_devices() -> int: logger.info("Updating devices") leases = fetch_leases( - mikrotik_settings.MIKROTIK_URL, mikrotik_settings.MIKROTIK_USER, mikrotik_settings.MIKROTIK_PASS + mikrotik_settings.MIKROTIK_URL, + mikrotik_settings.MIKROTIK_USER, + mikrotik_settings.MIKROTIK_PASS, ) logger.debug(f"Fetched leases: {leases}") for lease in leases: - device = Device(lease.mac_address, lease.host_name, lease.last_seen, lease.client_id, BitField()) #TODO figure out how to pass flags + device = Device( + lease.mac_address, + lease.host_name, + lease.last_seen, + lease.client_id, + BitField(), + ) # TODO figure out how to pass flags logger.debug(f"Processing Device: {device.__repr__()}") if device_repository.get_by_mac_address(lease.mac_address): device_repository.update(device) @@ -32,7 +41,11 @@ def update_devices() -> int: def run_worker(): if not all( - [mikrotik_settings.MIKROTIK_URL, mikrotik_settings.MIKROTIK_USER, mikrotik_settings.MIKROTIK_PASS] + [ + mikrotik_settings.MIKROTIK_URL, + mikrotik_settings.MIKROTIK_USER, + mikrotik_settings.MIKROTIK_PASS, + ] ): raise ValueError("Mikrotik settings not set") From c5ebf62e607aba07fa614b71b4b5b444595c8d60 Mon Sep 17 00:00:00 2001 From: Eduard Kaverinskyi Date: Mon, 3 Feb 2025 18:28:28 +0100 Subject: [PATCH 16/16] fix log in login() Signed-off-by: Eduard Kaverinskyi --- whois/app.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/whois/app.py b/whois/app.py index a0f3c4d..c63271c 100644 --- a/whois/app.py +++ b/whois/app.py @@ -355,7 +355,7 @@ def login(self): return redirect(url_for("devices")) else: self.logger.info( - f"Failed to log in: username={request.form["username"]}" + f'Failed to log in: username={request.form["username"]}' ) flash("Invalid credentials", "error")