jblu/qbit-maid
1
0 Fork 0
Code Issues Pull Requests Actions Packages Projects Releases 6 Wiki Activity

Improve logging: named logger, rotation, richer format #62

Merged
jblu merged 1 commits from logging-improvement into main 2026-10-27 00:31:29 -05:00
Conversation 0 Commits 1 Files Changed 6
+147 -65
6 changed files with 147 additions and 65 deletions
Download Patch File Download Diff File Expand all files Collapse all files
Showing only changes of commit ab30d69c7c - Show all commits

No files matched your search

README.md
+21
View File
@@ -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/<uuid>>"
```
## 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.
```
config.toml.example
+3
View File
@@ -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"
qbit-maid.py
+12 -12
View File
@@ -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()
qlist.py
+9 -16
View File
@@ -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)
qlogging.py
+88 -14
View File
@@ -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)
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)
qprocess.py
+14 -23
View File
@@ -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)