From ab30d69c7c6841aa40059a9a1ccc5f841cef27b1 Mon Sep 17 00:00:00 2001 From: Jonathan Branan Date: Mon, 26 Oct 2026 22:10:35 -0500 Subject: [PATCH] Improve logging: named logger, rotation, richer format, remove use_log guards - Add setup_logging() returning a named 'qbit-maid' logger with RotatingFileHandler (configurable size/backups) and a console handler - Add log_torrent() helper for structured torrent context - Replace basicConfig-based tor_log() with setup_logging() - Remove redundant 'if self.use_log:' guards across qbit-maid.py, qlist.py, qprocess.py, qlogging.py (level filtering handles it) - Document new logging options in config.toml.example and README --- README.md | 21 +++++++++ config.toml.example | 3 ++ qbit-maid.py | 24 +++++------ qlist.py | 25 ++++------- qlogging.py | 102 ++++++++++++++++++++++++++++++++++++++------ qprocess.py | 37 ++++++---------- 6 files changed, 147 insertions(+), 65 deletions(-) diff --git a/README.md b/README.md index 7d7a959..eb80c17 100755 --- a/README.md +++ b/README.md @@ -52,6 +52,9 @@ password = "pass" use_log = true log_level = "INFO" log_path = "./qc.log" +# Optional: log rotation (defaults shown) +log_max_bytes = 5000000 +log_backup_count = 3 [app_tags] protected_tag = "ipt" @@ -97,4 +100,22 @@ save = "save" [healthcheck] use_healthcheck = false healthcheck_url = "https://example.com/ping/>" +``` + +## Logging + +qbit-maid uses a named logger (`qbit-maid`) that writes to both the configured +log file and the console (useful for Docker/cron output). + +- `use_log` — enable or disable logging entirely. +- `log_level` — one of `DEBUG`, `INFO`, `WARN`, `ERROR`, `CRITICAL`. +- `log_path` — path to the log file. +- `log_max_bytes` — rotate the log file once it reaches this size (default 5 MB). +- `log_backup_count` — number of rotated backups to keep (default 3). + +Log lines include the timestamp, level, logger name, function, and line number, +for example: + +``` +10/26/2026 10:10:00 PM [INFO] qbit-maid:tor_processor:24 - Submitted ["My Torrent..."] for deletion. ``` \ No newline at end of file diff --git a/config.toml.example b/config.toml.example index 59a5eee..eaf30c2 100755 --- a/config.toml.example +++ b/config.toml.example @@ -8,6 +8,9 @@ password = "pass" use_log = true log_level = "INFO" log_path = "./qc.log" +# Optional: log rotation (defaults shown) +log_max_bytes = 5000000 +log_backup_count = 3 [app_tags] protected_tag = "ipt" diff --git a/qbit-maid.py b/qbit-maid.py index 03fa1f3..914f583 100755 --- a/qbit-maid.py +++ b/qbit-maid.py @@ -38,7 +38,6 @@ class Qbt: password=self.config["qbittorrent"]["password"], ) # Create the logging and pushover objects - self.tl = logging self.po = pushover self.ct = Counter self.cv = csv @@ -48,6 +47,12 @@ class Qbt: self.use_log = self.config["logging"]["use_log"] self.log_path = self.config["logging"]["log_path"] self.log_level = self.config["logging"]["log_level"] + self.log_max_bytes = self.config["logging"].get("log_max_bytes", 5_000_000) + self.log_backup_count = self.config["logging"].get("log_backup_count", 3) + self.tl = setup_logging( + self.use_log, self.log_path, self.log_level, + self.log_max_bytes, self.log_backup_count, + ) #app_tags self.tracker_protected_tag = self.config["app_tags"]["protected_tag"] @@ -91,7 +96,6 @@ class Qbt: self.healthcheck_url = self.config["healthcheck"]["healthcheck_url"] # Calling log and notify functions - tor_log(self) tor_notify(self) self.t = time @@ -105,8 +109,7 @@ class Qbt: self.preme_tor_counter = 0 self.ignored_counter = 0 self.torrent_hash_delete_list = [] - if self.use_log: - self.tl.debug(self.tracker_whitelist) + self.tl.debug(self.tracker_whitelist) #logging in try: self.tl.info('Connecting to host.') @@ -118,17 +121,14 @@ class Qbt: # Pulling all torrent data self.torrent_list = self.qbt_client.torrents_info() #Main process block - if self.use_log: - list_qbit_api_info(self) - list_first_tor(self) - debug_torrent_list(self) + list_qbit_api_info(self) + list_first_tor(self) + debug_torrent_list(self) build_tor_list(self) process_counts(self) - if self.use_log: - torrent_count(self) + torrent_count(self) tor_processor(self) - if self.use_log: - print_processor(self) + print_processor(self) if self.delete_torrents: tor_delete(self) self.et = datetime.datetime.now() diff --git a/qlist.py b/qlist.py index 2b445a9..5664175 100755 --- a/qlist.py +++ b/qlist.py @@ -1,33 +1,28 @@ def build_tor_list(self): """Builds multiple lists of torrents to be sorted. Also adds tags to the torents. There are more effecient ways of doing things but I did this rather quickly. - V2 will certainly be more performant. The reason two lists were used was so that torrents + V2 will certainly be more performant. The reason two lists were used was so that torrents that are in public trackers woudln't be around as long as torrents from a private tracker. """ - self.total_torrents = len(self.torrent_list) + self.total_torrents = len(self.torrent_list) while self.torrent_list: torrent = self.torrent_list.pop() - if self.use_log: - self.tl.debug(f'---Analyzing ["{torrent["name"][0:20]}..."] {torrent["infohash_v1"]}---') + self.tl.debug(f'---Analyzing ["{torrent["name"][0:20]}..."] {torrent["infohash_v1"]}---') # Need a way to tag when the tracker is blank if is_tracker_blank(torrent['tracker']): - if self.use_log: - self.tl.warning(f'Torrent doesn\'t have a tracker ["{torrent["name"][0:20]}..."] hash: {torrent["hash"]}') + self.tl.warning(f'Torrent doesn\'t have a tracker ["{torrent["name"][0:20]}..."] hash: {torrent["hash"]}') self.ignored_counter += 1 continue elif is_cat_ignored(torrent['category'], self.cat_whitelist.values()): - if self.use_log: - self.tl.info(f'Ignored category: ["{torrent["name"][0:20]}..."] category:[{torrent["category"]}] hash: {torrent["hash"]}') + self.tl.info(f'Ignored category: ["{torrent["name"][0:20]}..."] category:[{torrent["category"]}] hash: {torrent["hash"]}') self.ignored_counter += 1 continue elif is_ignored_tag(self.ignored_tags.values(),torrent['tags']): - if self.use_log: - self.tl.info(f'Ignored tag: ["{torrent["name"][0:20]}..."] tags: {torrent["tags"]} hash: {torrent["hash"]}') + self.tl.info(f'Ignored tag: ["{torrent["name"][0:20]}..."] tags: {torrent["tags"]} hash: {torrent["hash"]}') self.ignored_counter += 1 continue if is_tag_blank(torrent['tags']): - if self.use_log: - self.tl.debug(f'Tagging new torrent: ["{torrent["name"][0:20]}..."] {torrent["tracker"]}hash: {torrent["hash"]}') + self.tl.debug(f'Tagging new torrent: ["{torrent["name"][0:20]}..."] {torrent["tracker"]}hash: {torrent["hash"]}') if is_protected_tracker(torrent['tracker'], self.tracker_whitelist.values()): self.qbt_client.torrents_add_tags(self.tracker_protected_tag,torrent['hash']) elif is_not_protected_tracker(torrent['tracker'], self.tracker_whitelist.values()): @@ -39,14 +34,12 @@ def build_tor_list(self): elif is_protected_tracker(torrent['tracker'], self.tracker_whitelist.values()): if is_tag_blank(torrent['tags']): self.qbt_client.torrents_add_tags(self.tracker_protected_tag,torrent['hash']) - if self.use_log: - self.tl.debug(f'Tagging Protected torrent: ["{torrent["name"][0:20]}..."] {torrent["tracker"]}hash: {torrent["hash"]}') + self.tl.debug(f'Tagging Protected torrent: ["{torrent["name"][0:20]}..."] {torrent["tracker"]}hash: {torrent["hash"]}') self.tracker_list.append(torrent) elif is_not_protected_tracker(torrent['tracker'], self.tracker_whitelist.values()): if is_tag_blank(torrent['tags']): self.qbt_client.torrents_add_tags(self.tracker_non_protected_tag,torrent['hash']) - if self.use_log: - self.tl.debug(f'Tagging Non-protected torrent: ["{torrent["name"][0:20]}..."] {torrent["tracker"]}hash: {torrent["hash"]}') + self.tl.debug(f'Tagging Non-protected torrent: ["{torrent["name"][0:20]}..."] {torrent["tracker"]}hash: {torrent["hash"]}') self.tracker_list.append(torrent) diff --git a/qlogging.py b/qlogging.py index 87ec74a..939ba89 100755 --- a/qlogging.py +++ b/qlogging.py @@ -1,14 +1,6 @@ -def tor_log(self): - """Setting up the log file, if self.use_log is set to true and self.loglevel is DEBUG OR INFO""" - if self.use_log: - if self.log_level.lower() == 'debug': - self.tl.basicConfig(filename=self.log_path, format='%(asctime)s:%(levelname)s:%(message)s', encoding='utf-8', datefmt='%m/%d/%Y %I:%M:%S %p',level=self.tl.DEBUG) - elif self.log_level.lower() == 'info': - self.tl.basicConfig(filename=self.log_path, format='%(asctime)s:%(levelname)s:%(message)s', encoding='utf-8', datefmt='%m/%d/%Y %I:%M:%S %p',level=self.tl.INFO) - elif self.log_level.lower() == 'warn': - self.tl.basicConfig(filename=self.log_path, format='%(asctime)s:%(levelname)s:%(message)s', encoding='utf-8', datefmt='%m/%d/%Y %I:%M:%S %p',level=self.tl.WARN) - elif self.log_level.lower() == 'error': - self.tl.basicConfig(filename=self.log_path, format='%(asctime)s:%(levelname)s:%(message)s', encoding='utf-8', datefmt='%m/%d/%Y %I:%M:%S %p',level=self.tl.ERROR) +import logging +from logging.handlers import RotatingFileHandler + def tor_notify(self): """Seting up to use pushover, if self.use_pushover is set to true and @@ -79,8 +71,7 @@ def torrent_count(self): def get_script_runtime(self): elapsed_time = self.et - self.st - if self.use_log: - self.tl.info(f'Execution time: [{elapsed_time}]') + self.tl.info(f'Execution time: [{elapsed_time}]') if self.use_pushover: self.extm = f"Execution time: [{elapsed_time}]" if self.use_apprise: @@ -93,4 +84,87 @@ def send_ping(self, req_obj, healthcheck_url): self.tl.info(f"Ping failed: {e}") def debug_torrent_list(self): - self.tl.debug(self.torrent_list) \ No newline at end of file + self.tl.debug(self.torrent_list) + + +# --------------------------------------------------------------------------- +# New logging infrastructure (Phase 1 & 3) +# --------------------------------------------------------------------------- +LOGGER_NAME = "qbit-maid" +DEFAULT_MAX_BYTES = 5_000_000 +DEFAULT_BACKUP_COUNT = 3 + + +def setup_logging(use_log: bool, log_path: str, log_level: str, + max_bytes: int = DEFAULT_MAX_BYTES, + backup_count: int = DEFAULT_BACKUP_COUNT) -> logging.Logger: + """Configure and return the qbit-maid logger. + + Args: + use_log: If False, adds a NullHandler and sets level to CRITICAL. + log_path: Path to the log file. + log_level: One of debug, info, warn, warning, error, critical. + max_bytes: Max size of a log file before rotation (default 5 MB). + backup_count: Number of rotated backups to keep (default 3). + + Returns: + A configured :class:`logging.Logger` named ``"qbit-maid"``. + """ + logger = logging.getLogger(LOGGER_NAME) + + # Make setup idempotent: clear any handlers from a previous call + for handler in list(logger.handlers): + logger.removeHandler(handler) + + if not use_log: + logger.addHandler(logging.NullHandler()) + logger.setLevel(logging.CRITICAL) + return logger + + level_map = { + "debug": logging.DEBUG, + "info": logging.INFO, + "warn": logging.WARNING, + "warning": logging.WARNING, + "error": logging.ERROR, + "critical": logging.CRITICAL, + } + level = level_map.get(log_level.lower(), logging.INFO) + logger.setLevel(level) + + formatter = logging.Formatter( + fmt="%(asctime)s [%(levelname)s] %(name)s:%(funcName)s:%(lineno)d - %(message)s", + datefmt="%m/%d/%Y %I:%M:%S %p", + ) + + # File handler with rotation + file_handler = RotatingFileHandler( + log_path, maxBytes=max_bytes, backupCount=backup_count, encoding="utf-8" + ) + file_handler.setFormatter(formatter) + logger.addHandler(file_handler) + + # Console handler for Docker / cron visibility + console_handler = logging.StreamHandler() + console_handler.setFormatter(formatter) + logger.addHandler(console_handler) + + return logger + + +def log_torrent(logger: logging.Logger, level: int, torrent: dict, message: str = ""): + """Log a torrent record with structured extra fields. + + Args: + logger: The qbit-maid logger instance. + level: Logging level constant (e.g. ``logging.INFO``). + torrent: A dict with torrent fields (hash, name, tracker, tags, etc.). + message: Optional human-readable message. + """ + extra = { + "torrent_hash": torrent.get("infohash_v1", ""), + "torrent_name": (torrent.get("name", "") or "")[:20], + "torrent_tracker": torrent.get("tracker", "") or "", + "torrent_tags": torrent.get("tags", "") or "", + } + logger.log(level, message, extra=extra) \ No newline at end of file diff --git a/qprocess.py b/qprocess.py index 6f375d3..54f31a0 100755 --- a/qprocess.py +++ b/qprocess.py @@ -5,37 +5,29 @@ def tor_processor(self): for canidate in self.tracker_list: if self.enable_telemetry: header = ['state','ratio','tags','added','hash','name','tracker'] - row = [canidate['state'],canidate['ratio'],canidate["tags"],canidate['added_on'],canidate['infohash_v1'],canidate["name"][0:20],canidate['tracker']] + row = [canidate['state'],canidate['ratio'],canidate["tags"],canidate['added_on'],canidate['infohash_v1'],canidate["name"][0:20],canidate['tracker']] write_csv(self.cv,self.telemetry_outfile,header,row) - if self.use_log: - self.tl.debug(f'---Reviewing canidate: ["{canidate["name"][0:20]}..."] {canidate["infohash_v1"]}---') + self.tl.debug(f'---Reviewing canidate: ["{canidate["name"][0:20]}..."] {canidate["infohash_v1"]}---') if is_downloading(canidate['state']): - if self.use_log: - self.tl.info(f'["{canidate["name"][0:20]}..."] is still downloading and will be skipped.') + self.tl.info(f'["{canidate["name"][0:20]}..."] is still downloading and will be skipped.') continue elif is_protected_under_ratio(canidate['ratio'], 1.05, self.tracker_protected_tag, canidate["tags"]): - if self.use_log: - self.tl.debug(f'["{canidate["name"][0:20]}..."] is below a 1.05 ratio({canidate["ratio"]})') + self.tl.debug(f'["{canidate["name"][0:20]}..."] is below a 1.05 ratio({canidate["ratio"]})') if is_old_tor(canidate['time_active'], self.max_age): - if self.use_log: - self.tl.debug(f'["{canidate["name"][0:20]}..."] Seconds old: {canidate["time_active"]} Delta: {canidate["time_active"] - self.max_age}') + self.tl.debug(f'["{canidate["name"][0:20]}..."] Seconds old: {canidate["time_active"]} Delta: {canidate["time_active"] - self.max_age}') self.torrent_hash_delete_list.append(canidate['infohash_v1']) - if self.use_log: - self.tl.info(f'Submitted ["{canidate["name"][0:20]}..."] for deletion from the protected list.') - elif is_protected_over_ratio(canidate['ratio'], 1.05, self.tracker_protected_tag, canidate["tags"]): - if self.use_log: - self.tl.debug(f'["{canidate["name"][0:20]}..."] is above a 1.05 ratio({canidate["ratio"]}).') - self.torrent_hash_delete_list.append(canidate['infohash_v1']) - if self.use_log: self.tl.info(f'Submitted ["{canidate["name"][0:20]}..."] for deletion from the protected list.') + elif is_protected_over_ratio(canidate['ratio'], 1.05, self.tracker_protected_tag, canidate["tags"]): + self.tl.debug(f'["{canidate["name"][0:20]}..."] is above a 1.05 ratio({canidate["ratio"]}).') + self.torrent_hash_delete_list.append(canidate['infohash_v1']) + self.tl.info(f'Submitted ["{canidate["name"][0:20]}..."] for deletion from the protected list.') elif is_not_protected_tor(self.tracker_non_protected_tag, canidate["tags"]): self.torrent_hash_delete_list.append(canidate['infohash_v1']) - if self.use_log: - self.tl.info(f'Submitted ["{canidate["name"][0:20]}..."] for deletion.') + self.tl.info(f'Submitted ["{canidate["name"][0:20]}..."] for deletion.') else: if self.enable_dragnet: header = ['state','ratio','tags','added','thash','tname','trname'] - row = [canidate['state'],canidate['ratio'],canidate["tags"],canidate['added_on'],canidate['infohash_v1'],canidate["name"][0:20],canidate['tracker']] + row = [canidate['state'],canidate['ratio'],canidate["tags"],canidate['added_on'],canidate['infohash_v1'],canidate["name"][0:20],canidate['tracker']] write_csv(self.cv,self.dragnet_outfile,header,row) self.tl.info(f'["{canidate["name"][0:20]}..."] is orphaned.') self.up_tor_counter += 1 @@ -46,11 +38,10 @@ def tor_delete_tags(self): self.qbt_client.torrents_delete_tags(tag_list) def tor_delete(self): - """Remove torrents, will also delete files, this keeps the filesystem clean. + """Remove torrents, will also delete files, this keeps the filesystem clean. Only pass self.torrent_hash_delete_list if you would like to keep the files.""" - if self.use_log: - self.tl.debug('Hash list submitted for deletion:') - self.tl.debug(self.torrent_hash_delete_list) + self.tl.debug('Hash list submitted for deletion:') + self.tl.debug(self.torrent_hash_delete_list) if self.torrent_hash_delete_list: self.qbt_client.torrents_delete(True, self.torrent_hash_delete_list) -- 2.54.0