From 13074f56cbc0af5eaba31c8aca0268fc890444c4 Mon Sep 17 00:00:00 2001 From: Dmitrii Iurco Date: Wed, 10 Jun 2026 19:14:01 -0400 Subject: [PATCH] fix: logging verbosity now actually applies + per-service log levels Root causes fixed: - Dead LOG_LEVEL globals() lookup pinned root logger at INFO regardless of PIC_LOG_LEVEL env or config; replaced with _resolve_root_log_level() + apply_root_log_level() which sets both root logger and all attached handlers at startup and on runtime re-apply. - set_service_level() only set the named 'pic.' logger; bare module loggers (e.g. 'caddy_manager') were never reached, so per-service log files stayed 0 bytes. Fixed via _SERVICE_MODULE_LOGGERS map covering all managers. - Log viewer GET /api/logs had no level filter; added ?level= query param. - Per-service log levels lived in an out-of-band config/api/log_levels.json side-file with no validation; migrated into ConfigManager under a new 'logging' section ({python:{root,services}, containers:{caddy,coredns, wireguard,mailserver,api}}) with get/set helpers, invalid-level rejection, and one-time migration from the old file on first load. New capabilities: - Container log levels: Caddy (injects global log { level X } + hot reload), CoreDNS (DEBUG enables log plugin, else errors-only), WireGuard/mailserver via pending_restart path. - PUT /api/logs/verbosity accepts {python, containers} dict; returns per-entry applied:hot|pending_restart status. - Webui Logs page gains two-section Verbosity tab (Python services + Container services) with needs-restart badges. - managers.py wires per-service loggers before manager instantiation and re-applies persisted levels from ConfigManager; legacy log_levels.json read removed. Co-Authored-By: Claude Fable 5 --- api/app.py | 31 +++++- api/caddy_manager.py | 33 +++++- api/config_manager.py | 105 +++++++++++++++++++ api/firewall_manager.py | 42 ++++++-- api/log_manager.py | 24 ++++- api/managers.py | 53 +++++----- api/routes/services.py | 91 +++++++++++++---- tests/test_caddy_manager.py | 29 ++++++ tests/test_cell_link_dns.py | 11 +- tests/test_firewall_manager.py | 14 +++ tests/test_log_manager_extra.py | 17 ++++ tests/test_logging_config.py | 97 ++++++++++++++++++ tests/test_logs_endpoints.py | 119 ++++++++++++++++------ tests/test_routes_services_catalog.py | 77 +++++++------- webui/src/pages/Logs.jsx | 141 +++++++++++++++++++------- 15 files changed, 726 insertions(+), 158 deletions(-) create mode 100644 tests/test_logging_config.py diff --git a/api/app.py b/api/app.py index 39d7d1f..0a6ff64 100644 --- a/api/app.py +++ b/api/app.py @@ -59,8 +59,18 @@ from legacy_cleanup import cleanup_legacy_builtin_containers # Context variable for request info request_context = contextvars.ContextVar('request_context', default={}) -# Set default log level and log file if not already defined -LOG_LEVEL = globals().get('LOG_LEVEL', 'INFO') +def _resolve_root_log_level(): + """Resolve the root python log level from PIC_LOG_LEVEL env, then the + ConfigManager logging.python.root setting, defaulting to INFO.""" + env_level = os.environ.get('PIC_LOG_LEVEL', '').strip().upper() + if env_level in ('DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL'): + return env_level + try: + return config_manager.get_logging_config()['python']['root'] + except Exception: + return 'INFO' + +LOG_LEVEL = _resolve_root_log_level() LOG_FILE = globals().get('LOG_FILE', 'picell.log') class ContextFilter(logging.Filter): @@ -111,6 +121,23 @@ logging.basicConfig( ) logger = logging.getLogger('picell') + +def apply_root_log_level(level=None): + """(Re)apply the root python log level at runtime. + + Sets the ROOT logger level and every root handler level so that bare-module + loggers (e.g. firewall_manager, network_manager) — which log via + logging.getLogger(__name__) and propagate to root — are governed. When + ``level`` is None the level is re-resolved from env/ConfigManager. + """ + resolved = (level or _resolve_root_log_level()).upper() + numeric = getattr(logging, resolved, logging.INFO) + root = logging.getLogger() + root.setLevel(numeric) + for h in root.handlers: + h.setLevel(numeric) + return resolved + # Flask app setup app = Flask(__name__) CORS(app, diff --git a/api/caddy_manager.py b/api/caddy_manager.py index a203f43..4c8a81d 100644 --- a/api/caddy_manager.py +++ b/api/caddy_manager.py @@ -111,6 +111,30 @@ class CaddyManager(BaseServiceManager): # ── Caddyfile generation ────────────────────────────────────────────── + # Python logging level → Caddy log level. Caddy only knows + # DEBUG/INFO/WARN/ERROR (no CRITICAL). + _CADDY_LEVEL_MAP = { + 'DEBUG': 'DEBUG', 'INFO': 'INFO', 'WARNING': 'WARN', + 'ERROR': 'ERROR', 'CRITICAL': 'ERROR', + } + + def _resolve_caddy_level(self) -> str: + """Read the configured caddy container log level (Python level name).""" + if self.config_manager is not None: + try: + return self.config_manager.get_logging_config()['containers'].get('caddy', 'INFO') + except Exception: + pass + return 'INFO' + + def _global_log_block(self) -> str: + """Return the global-options `log { level }` line(s), or '' for the + Caddy default (INFO). Injected inside the global `{ ... }` block.""" + level = self._CADDY_LEVEL_MAP.get(self._resolve_caddy_level(), 'INFO') + if level == 'INFO': + return '' + return f" log {{\n level {level}\n }}" + def generate_caddyfile(self, identity: Dict[str, Any], installed_services: List[Dict[str, Any]]) -> str: """Generate a complete Caddyfile based on identity and services. @@ -172,13 +196,15 @@ class CaddyManager(BaseServiceManager): # ── per-mode generators ─────────────────────────────────────────────── - @staticmethod - def _global_acme_block(email: Optional[str]) -> str: + def _global_acme_block(self, email: Optional[str]) -> str: """Return the ``{ ... }`` global block for an ACME-enabled mode.""" lines = ["{"] # Bind admin API on all interfaces so cell-api can reach cell-caddy # across the Docker bridge (default 127.0.0.1 is unreachable cross-container). lines.append(" admin 0.0.0.0:2019") + log_block = self._global_log_block() + if log_block: + lines.append(log_block) if email: lines.append(f" email {email}") # Only write acme_ca when a URL is configured — an empty ACME_CA_URL @@ -290,9 +316,12 @@ class CaddyManager(BaseServiceManager): body.append(self._indent_routes(service_routes)) body.append(core_routes) inner = "\n".join(body) + log_block = self._global_log_block() + log_line = (log_block + "\n") if log_block else "" return ( "{\n" " admin 0.0.0.0:2019\n" + f"{log_line}" " auto_https off\n" "}\n" "\n" diff --git a/api/config_manager.py b/api/config_manager.py index f07fc64..8938630 100644 --- a/api/config_manager.py +++ b/api/config_manager.py @@ -44,6 +44,31 @@ _BACKUP_EXCLUDE_FILES = ( logger = logging.getLogger(__name__) +# Valid Python logging levels for the `logging` config section. +_VALID_LOG_LEVELS = ('DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL') + +# Per-service Python loggers exposed in the verbosity panel. +_LOGGING_PYTHON_SERVICES = ( + 'network', 'wireguard', 'email', 'calendar', + 'files', 'routing', 'vault', 'api', +) + +# Container services whose log level we can influence (hot for caddy/coredns, +# pending_restart for env-driven containers). +_LOGGING_CONTAINERS = ('caddy', 'coredns', 'wireguard', 'mailserver', 'api') + + +def _default_logging_config() -> Dict[str, Any]: + """Return the default `logging` section for cell_config.""" + return { + 'python': { + 'root': 'INFO', + 'services': {svc: 'INFO' for svc in _LOGGING_PYTHON_SERVICES}, + }, + 'containers': {c: 'INFO' for c in _LOGGING_CONTAINERS}, + } + + class ConfigManager: """Centralized configuration management for all services (unified config)""" @@ -75,6 +100,7 @@ class ConfigManager: # Phase 5: ensure connectivity section exists with empty defaults. if 'connectivity' not in self.configs: self.configs['connectivity'] = {'exits': {}, 'peer_exit_map': {}} + self._ensure_logging_config() if not self.config_file.exists(): self._save_all_configs() # Silent migration: when DDNS is active but the internal domain is still @@ -976,6 +1002,85 @@ class ConfigManager: ident.setdefault('service_ips', {}).pop(service_id, None) self._save_all_configs() + # ── Logging verbosity configuration ─────────────────────────────────── + def _ensure_logging_config(self) -> None: + """Ensure a well-formed `logging` section exists, migrating the legacy + config/api/log_levels.json side-file on first load. + + The legacy file held a flat {service: LEVEL} map for the picell.* python + loggers. It is read once and merged in; the section then becomes the + single source of truth (the side-file is ignored thereafter). + """ + cfg = self.configs.get('logging') + if not isinstance(cfg, dict): + cfg = _default_logging_config() + self.configs['logging'] = cfg + + python = cfg.setdefault('python', {}) + if not python.get('root') or python['root'] not in _VALID_LOG_LEVELS: + python['root'] = 'INFO' + services = python.setdefault('services', {}) + for svc in _LOGGING_PYTHON_SERVICES: + if services.get(svc) not in _VALID_LOG_LEVELS: + services.setdefault(svc, 'INFO') + + containers = cfg.setdefault('containers', {}) + for c in _LOGGING_CONTAINERS: + if containers.get(c) not in _VALID_LOG_LEVELS: + containers.setdefault(c, 'INFO') + + # One-time migration from the legacy side-file. + if not cfg.get('_migrated_log_levels'): + legacy = self.config_file.parent / 'api' / 'log_levels.json' + legacy_flat = self.config_file.parent / 'log_levels.json' + for path in (legacy, legacy_flat): + try: + if path.exists(): + with open(path) as lf: + for svc, lvl in (json.load(lf) or {}).items(): + if (isinstance(lvl, str) + and lvl.upper() in _VALID_LOG_LEVELS + and svc in services): + services[svc] = lvl.upper() + except Exception as e: + logger.warning('log_levels.json migration skipped (%s): %s', path, e) + cfg['_migrated_log_levels'] = True + + def get_logging_config(self) -> Dict[str, Any]: + """Return the full logging config (python + containers sections).""" + self._ensure_logging_config() + cfg = self.configs['logging'] + return { + 'python': { + 'root': cfg['python']['root'], + 'services': dict(cfg['python']['services']), + }, + 'containers': dict(cfg['containers']), + } + + def set_python_log_level(self, service: str, level: str) -> None: + """Persist a python service (or 'root') log level. Raises ValueError on + an invalid level.""" + level = (level or '').upper() + if level not in _VALID_LOG_LEVELS: + raise ValueError(f"Invalid log level: {level!r}") + self._ensure_logging_config() + python = self.configs['logging']['python'] + if service == 'root': + python['root'] = level + else: + python.setdefault('services', {})[service] = level + self._save_all_configs() + + def set_container_log_level(self, container: str, level: str) -> None: + """Persist a container log level. Raises ValueError on an invalid level.""" + level = (level or '').upper() + if level not in _VALID_LOG_LEVELS: + raise ValueError(f"Invalid log level: {level!r}") + self._ensure_logging_config() + self.configs['logging']['containers'][container] = level + self._save_all_configs() + # Phase 5 — Extended connectivity configuration helpers def get_connectivity_config(self) -> Dict[str, Any]: """Return the full connectivity config (exits + peer_exit_map).""" diff --git a/api/firewall_manager.py b/api/firewall_manager.py index f1793eb..9f81c52 100644 --- a/api/firewall_manager.py +++ b/api/firewall_manager.py @@ -41,6 +41,18 @@ CADDY_CONTAINER = 'cell-caddy' COREFILE_PATH = '/app/config/dns/Corefile' ZONE_DATA_DIR = '/data' # inside CoreDNS container; mounted from ./data/dns +# Optional callable wired by managers.py that returns the persisted CoreDNS log +# level (Python level name). Lets generate_corefile keep the configured level +# sticky across regenerations triggered for unrelated reasons (peer changes, +# IP-range edits) without threading config_manager through every call site. +_coredns_level_resolver = None + + +def set_coredns_level_resolver(resolver) -> None: + """Wire the persisted-CoreDNS-level resolver (called once at startup).""" + global _coredns_level_resolver + _coredns_level_resolver = resolver + def _run(cmd: List[str], check: bool = True) -> subprocess.CompletedProcess: """Run a shell command and return the result.""" @@ -709,10 +721,21 @@ def _build_acl_block(blocked_peers_by_service: Dict[str, List[str]], return '\n'.join(lines) +def _coredns_log_directive(level: str) -> str: + """Return the per-block logging directive line for CoreDNS. + + DEBUG → the verbose `log` query-logging plugin. Any higher level → `errors` + only (CoreDNS has no INFO/WARN query-log granularity), keeping the per-cell + DNS logs quiet by default. + """ + return 'log' if (level or 'INFO').upper() == 'DEBUG' else 'errors' + + def generate_corefile(peers: List[Dict[str, Any]], corefile_path: str = COREFILE_PATH, domain: str = 'cell', cell_links: Optional[List[Dict[str, Any]]] = None, - split_horizon_zones: Optional[List[str]] = None) -> bool: + split_horizon_zones: Optional[List[str]] = None, + coredns_level: Optional[str] = None) -> bool: """ Rewrite the CoreDNS Corefile with per-peer ACL rules and reload plugin. The file is written to corefile_path (API-side path mapped into CoreDNS container). @@ -739,7 +762,14 @@ def generate_corefile(peers: List[Dict[str, Any]], corefile_path: str = COREFILE acl_block = _build_acl_block(blocked, domain) - primary_zone_block = f'{domain} {{\n file /data/{domain}.zone\n log\n' + if coredns_level is None and _coredns_level_resolver is not None: + try: + coredns_level = _coredns_level_resolver() + except Exception: + coredns_level = 'INFO' + log_directive = _coredns_log_directive(coredns_level) + + primary_zone_block = f'{domain} {{\n file /data/{domain}.zone\n {log_directive}\n' if acl_block: primary_zone_block += acl_block + '\n' primary_zone_block += '}\n' @@ -747,7 +777,7 @@ def generate_corefile(peers: List[Dict[str, Any]], corefile_path: str = COREFILE corefile = f""". {{ forward . 8.8.8.8 1.1.1.1 cache - log + {log_directive} health reload }} @@ -767,13 +797,13 @@ def generate_corefile(peers: List[Dict[str, Any]], corefile_path: str = COREFILE f'\n_acme-challenge.{sz} {{\n' f' forward . 8.8.8.8 1.1.1.1\n' f' cache\n' - f' log\n' + f' {log_directive}\n' f'}}\n' ) corefile += ( f'\n{sz} {{\n' f' file /data/{sz}.zone\n' - f' log\n' + f' {log_directive}\n' f'}}\n' ) @@ -788,7 +818,7 @@ def generate_corefile(peers: List[Dict[str, Any]], corefile_path: str = COREFILE f'\n{link_domain} {{\n' f' forward . {link_dns_ip}\n' f' cache\n' - f' log\n' + f' {log_directive}\n' f'}}\n' ) elif not split_horizon_zones: diff --git a/api/log_manager.py b/api/log_manager.py index 723feea..875fade 100644 --- a/api/log_manager.py +++ b/api/log_manager.py @@ -21,6 +21,20 @@ from enum import Enum logger = logging.getLogger(__name__) +# Maps a verbosity-panel service name to the bare module logger(s) used by the +# corresponding manager (logging.getLogger(__name__)). Managers log under BOTH +# 'picell.' (self.logger) and their module name, so a verbosity change +# must reach both for per-service log files to capture everything. +_SERVICE_MODULE_LOGGERS = { + 'network': ['network_manager'], + 'wireguard': ['wireguard_manager'], + 'email': ['email_manager'], + 'calendar': ['calendar_manager'], + 'files': ['file_manager'], + 'routing': ['routing_manager', 'firewall_manager'], + 'vault': ['vault_manager'], +} + class LogLevel(Enum): """Log levels""" DEBUG = "DEBUG" @@ -499,7 +513,13 @@ class LogManager: return {'error': str(e)} def set_service_level(self, service: str, level: str): - """Change log level for a service at runtime.""" + """Change log level for a service at runtime. + + Sets BOTH the 'picell.' logger (self.logger in managers) AND the + bare module logger(s) the manager uses via logging.getLogger(__name__), + so the change reaches every record a service emits — not just the half + that goes through self.logger. + """ try: log_level = getattr(logging, level.upper(), logging.INFO) if service in self.service_loggers: @@ -509,6 +529,8 @@ class LogManager: logger.info(f"Set log level for {service} to {level}") else: logger.warning(f"Service logger not found: {service}") + for module_name in _SERVICE_MODULE_LOGGERS.get(service, []): + logging.getLogger(module_name).setLevel(log_level) except Exception as e: logger.error(f"Error setting log level for {service}: {e}") diff --git a/api/managers.py b/api/managers.py index 1e312a1..67e4904 100644 --- a/api/managers.py +++ b/api/managers.py @@ -45,6 +45,22 @@ config_manager = ConfigManager( service_bus = ServiceBus() log_manager = LogManager(log_dir='./data/logs') +# Attach per-service file loggers BEFORE any manager is instantiated. Managers +# log during __init__ via self.logger ('picell.'); without the handlers in +# place first, those early records would be lost from the per-service log files. +_service_log_configs = { + 'network': {'level': 'INFO', 'formatter': 'json', 'console': False}, + 'wireguard': {'level': 'INFO', 'formatter': 'json', 'console': False}, + 'email': {'level': 'INFO', 'formatter': 'json', 'console': False}, + 'calendar': {'level': 'INFO', 'formatter': 'json', 'console': False}, + 'files': {'level': 'INFO', 'formatter': 'json', 'console': False}, + 'routing': {'level': 'INFO', 'formatter': 'json', 'console': False}, + 'vault': {'level': 'INFO', 'formatter': 'json', 'console': False}, + 'api': {'level': 'INFO', 'formatter': 'json', 'console': True}, +} +for _svc, _cfg in _service_log_configs.items(): + log_manager.add_service_logger(_svc, _cfg) + # ServiceRegistry depends only on config_manager; create it early so # NetworkManager and CaddyManager can derive subdomains from manifests # instead of hardcoding service names. @@ -112,30 +128,21 @@ service_store_manager.egress_manager = egress_manager setup_manager = SetupManager(config_manager=config_manager, auth_manager=auth_manager, network_manager=network_manager) -# Service logger configuration -_service_log_configs = { - 'network': {'level': 'INFO', 'formatter': 'json', 'console': False}, - 'wireguard': {'level': 'INFO', 'formatter': 'json', 'console': False}, - 'email': {'level': 'INFO', 'formatter': 'json', 'console': False}, - 'calendar': {'level': 'INFO', 'formatter': 'json', 'console': False}, - 'files': {'level': 'INFO', 'formatter': 'json', 'console': False}, - 'routing': {'level': 'INFO', 'formatter': 'json', 'console': False}, - 'vault': {'level': 'INFO', 'formatter': 'json', 'console': False}, - 'api': {'level': 'INFO', 'formatter': 'json', 'console': True}, -} -for _svc, _cfg in _service_log_configs.items(): - log_manager.add_service_logger(_svc, _cfg) +# Apply persisted per-service log levels from ConfigManager (single source of +# truth — the logging section of cell_config). This runs AFTER managers are +# instantiated so it overrides their default INFO and reaches the module loggers. +try: + _logging_cfg = config_manager.get_logging_config() + for _svc, _lvl in _logging_cfg['python']['services'].items(): + log_manager.set_service_level(_svc, _lvl) +except Exception: + pass -# Apply any persisted log level overrides (stored in the mounted config volume) -import json as _json -_levels_file = os.path.join(CONFIG_DIR, 'log_levels.json') -if os.path.exists(_levels_file): - try: - with open(_levels_file) as _lf: - for _s, _l in _json.load(_lf).items(): - log_manager.set_service_level(_s, _l) - except Exception: - pass +# Let generate_corefile keep the configured CoreDNS log level sticky across all +# regenerations, not just verbosity-triggered ones. +firewall_manager.set_coredns_level_resolver( + lambda: config_manager.get_logging_config()['containers'].get('coredns', 'INFO') +) service_bus.start() diff --git a/api/routes/services.py b/api/routes/services.py index 6f968aa..29c7fd2 100644 --- a/api/routes/services.py +++ b/api/routes/services.py @@ -332,40 +332,89 @@ def get_log_file_infos(): logger.error(f"Error listing log files: {e}") return jsonify({"error": str(e)}), 500 +# Container-ENV driven services need a container recreate before a level change +# takes effect (the others — caddy/coredns/api — apply hot). +_RESTART_CONTAINERS = {'wireguard', 'mailserver'} + + @bp.route('/api/logs/verbosity', methods=['GET']) def get_log_verbosity(): + """Return both the python (per-service + root) and container log levels.""" try: - from app import log_manager - return jsonify(log_manager.get_service_levels()) + from app import config_manager + return jsonify(config_manager.get_logging_config()) except Exception as e: logger.error(f"Error getting log verbosity: {e}") return jsonify({"error": str(e)}), 500 + @bp.route('/api/logs/verbosity', methods=['PUT']) def set_log_verbosity(): + """Update python and/or container log levels. + + Payload: {"python": {"root": "DEBUG", "services": {...}}, "containers": {...}} + Python levels apply hot to the running API. Container levels regenerate the + relevant config and hot-reload (caddy/coredns) or are queued for the next + container recreate (wireguard/mailserver). Returns an `applied` map of + "hot" | "pending_restart" per container entry. + """ try: - from app import log_manager + from app import config_manager, log_manager, apply_root_log_level data = request.get_json(silent=True) or {} - for service, level in data.items(): + python = data.get('python', {}) or {} + containers = data.get('containers', {}) or {} + + applied = {} + + services = python.get('services', {}) or {} + for service, level in services.items(): + config_manager.set_python_log_level(service, level) log_manager.set_service_level(service, level) - _config_dir = os.environ.get('CONFIG_DIR', '/app/config') - levels_file = os.path.join(_config_dir, 'log_levels.json') - os.makedirs(os.path.dirname(levels_file), exist_ok=True) - current = {} - if os.path.exists(levels_file): - try: - with open(levels_file) as f: - current = json.load(f) - except Exception: - pass - current.update(data) - with open(levels_file, 'w') as f: - json.dump(current, f, indent=2) - return jsonify({"message": "Log levels updated", "levels": log_manager.get_service_levels()}) + + if 'root' in python: + config_manager.set_python_log_level('root', python['root']) + apply_root_log_level(python['root']) + + for container, level in containers.items(): + config_manager.set_container_log_level(container, level) + applied[container] = _apply_container_level(container) + + return jsonify({ + "message": "Log levels updated", + "logging": config_manager.get_logging_config(), + "applied": applied, + }) + except ValueError as e: + return jsonify({"error": str(e)}), 400 except Exception as e: logger.error(f"Error setting log verbosity: {e}") return jsonify({"error": str(e)}), 500 + +def _apply_container_level(container: str) -> str: + """Apply a container's log level. Returns "hot" or "pending_restart".""" + if container == 'caddy': + from app import caddy_manager, config_manager + caddy_manager.regenerate_with_installed( + list(config_manager.get_installed_services().values()) + ) + return "hot" + if container == 'coredns': + from app import firewall_manager, peer_registry, config_manager, cell_link_manager + peers = peer_registry.list_peers() if peer_registry else [] + cell_links = cell_link_manager.list_connections() if cell_link_manager else None + firewall_manager.generate_corefile( + peers, domain=config_manager.get_internal_domain(), cell_links=cell_links) + firewall_manager.reload_coredns() + return "hot" + if container == 'api': + # The API container's own root level is applied hot via apply_root_log_level + # when python.root changes; the container entry is informational. + return "hot" + if container in _RESTART_CONTAINERS: + return "pending_restart" + return "pending_restart" + @bp.route('/api/services/status', methods=['GET']) def get_all_services_status(): try: @@ -467,12 +516,16 @@ def test_all_services_connectivity(): def get_backend_logs(): log_file = os.path.join(os.path.dirname(os.path.dirname(__file__)), 'picell.log') lines = int(request.args.get('lines', 100)) + level = (request.args.get('level') or 'ALL').upper() try: if not os.path.exists(log_file): return jsonify({"error": "Log file not found."}), 404 with open(log_file, 'r', encoding='utf-8', errors='ignore') as f: all_lines = f.readlines() - tail_lines = all_lines[-lines:] if lines > 0 else all_lines + if level != 'ALL': + from app import log_manager + all_lines = [ln for ln in all_lines if log_manager._is_log_level(ln, level)] + tail_lines = all_lines[-lines:] if lines > 0 else all_lines return jsonify({"log": ''.join(tail_lines)}) except Exception as e: logger.error(f"Error reading log file: {e}") diff --git a/tests/test_caddy_manager.py b/tests/test_caddy_manager.py index 9437d63..4e76739 100644 --- a/tests/test_caddy_manager.py +++ b/tests/test_caddy_manager.py @@ -735,5 +735,34 @@ class TestDdnsApiStripsLegacySuffix(unittest.TestCase): self.assertIn('api_base_url https://ddns.pic.ngo', out) +class TestCaddyLogLevel(unittest.TestCase): + """Container log level injects a global `log { level }` block.""" + + def _mgr_with_level(self, level): + cm = MagicMock() + cm.get_identity.return_value = {} + cm.get_logging_config.return_value = { + 'python': {'root': 'INFO', 'services': {}}, + 'containers': {'caddy': level}, + } + return CaddyManager(config_manager=cm, data_dir='/tmp/pic-t', config_dir='/tmp/pic-t') + + def test_debug_emits_global_log_block_lan(self): + mgr = self._mgr_with_level('DEBUG') + out = mgr.generate_caddyfile({'cell_name': 'c', 'domain_mode': 'lan'}, []) + self.assertIn('log {', out) + self.assertIn('level DEBUG', out) + + def test_info_emits_no_log_block(self): + mgr = self._mgr_with_level('INFO') + out = mgr.generate_caddyfile({'cell_name': 'c', 'domain_mode': 'lan'}, []) + self.assertNotIn('log {', out) + + def test_warning_maps_to_caddy_warn(self): + mgr = self._mgr_with_level('WARNING') + out = mgr.generate_caddyfile({'cell_name': 'c', 'domain_mode': 'lan'}, []) + self.assertIn('level WARN', out) + + if __name__ == '__main__': unittest.main() diff --git a/tests/test_cell_link_dns.py b/tests/test_cell_link_dns.py index 0f693f5..834ab8b 100644 --- a/tests/test_cell_link_dns.py +++ b/tests/test_cell_link_dns.py @@ -61,8 +61,17 @@ class TestGenerateCorefileOneLink(unittest.TestCase): self.assertIn('cache', content[idx_primary:]) def test_log_directive_present_in_forwarding_block(self): + # At default INFO the forwarding block carries the `errors` directive; + # at DEBUG it carries the verbose `log` plugin. cell_links = [{'domain': 'remote.cell', 'dns_ip': '10.5.0.1'}] - firewall_manager.generate_corefile([], self.path, cell_links=cell_links) + firewall_manager.generate_corefile([], self.path, cell_links=cell_links, + coredns_level='INFO') + content = self._read() + idx_primary = content.index('remote.cell {') + self.assertIn('errors', content[idx_primary:]) + + firewall_manager.generate_corefile([], self.path, cell_links=cell_links, + coredns_level='DEBUG') content = self._read() idx_primary = content.index('remote.cell {') self.assertIn('log', content[idx_primary:]) diff --git a/tests/test_firewall_manager.py b/tests/test_firewall_manager.py index f3cfd02..60dd147 100644 --- a/tests/test_firewall_manager.py +++ b/tests/test_firewall_manager.py @@ -132,6 +132,20 @@ class TestGenerateCorefile(unittest.TestCase): content = open(self.path).read() self.assertIn('reload', content) + def test_debug_level_includes_log_plugin(self): + firewall_manager.generate_corefile([], self.path, coredns_level='DEBUG') + content = open(self.path).read() + # The verbose query-logging `log` plugin is present at DEBUG. + self.assertIn('\n log\n', content) + self.assertNotIn('errors', content) + + def test_info_level_uses_errors_only(self): + firewall_manager.generate_corefile([], self.path, coredns_level='INFO') + content = open(self.path).read() + self.assertIn('errors', content) + # No verbose query logging at INFO. + self.assertNotIn('\n log\n', content) + def test_rewrite_preserves_inode(self): # Regression: the Corefile is a Docker FILE bind-mount, so it must be # rewritten in place. os.replace() would swap the inode and the diff --git a/tests/test_log_manager_extra.py b/tests/test_log_manager_extra.py index ee85333..9102212 100644 --- a/tests/test_log_manager_extra.py +++ b/tests/test_log_manager_extra.py @@ -356,6 +356,23 @@ class TestSetServiceLevel(unittest.TestCase): self.assertIsInstance(levels, dict) self.assertIn('svc', levels) + def test_set_level_also_sets_bare_module_logger(self): + """A verbosity change for 'network' must reach BOTH picell.network and + the network_manager module logger so per-service files capture every + record (the core bug).""" + import logging + self.lm.add_service_logger('network', {'level': 'INFO'}) + self.lm.set_service_level('network', 'DEBUG') + self.assertEqual(self.lm.service_loggers['network'].level, logging.DEBUG) + self.assertEqual(logging.getLogger('network_manager').level, logging.DEBUG) + + def test_set_level_for_routing_covers_firewall_module_logger(self): + import logging + self.lm.add_service_logger('routing', {'level': 'INFO'}) + self.lm.set_service_level('routing', 'DEBUG') + self.assertEqual(logging.getLogger('routing_manager').level, logging.DEBUG) + self.assertEqual(logging.getLogger('firewall_manager').level, logging.DEBUG) + class TestGetAllLogFileInfos(unittest.TestCase): def setUp(self): diff --git a/tests/test_logging_config.py b/tests/test_logging_config.py new file mode 100644 index 0000000..4064609 --- /dev/null +++ b/tests/test_logging_config.py @@ -0,0 +1,97 @@ +#!/usr/bin/env python3 +""" +Tests for the `logging` section of cell_config (ConfigManager): +- default schema present after first load +- round-trip persistence of python + container levels +- migration from the legacy config/api/log_levels.json side-file +- invalid-level rejection +- inclusion in the backed-up cell_config +""" + +import sys +import os +import json +import tempfile +import shutil +import unittest +from pathlib import Path + +api_dir = Path(__file__).parent.parent / 'api' +sys.path.insert(0, str(api_dir)) + +from config_manager import ConfigManager + + +def _make_cm(tmp): + config_file = os.path.join(tmp, 'cell_config.json') + data_dir = os.path.join(tmp, 'data') + os.makedirs(data_dir, exist_ok=True) + return ConfigManager(config_file, data_dir) + + +class TestLoggingSchema(unittest.TestCase): + def setUp(self): + self.tmp = tempfile.mkdtemp() + + def tearDown(self): + shutil.rmtree(self.tmp, ignore_errors=True) + + def test_default_logging_config_present(self): + cm = _make_cm(self.tmp) + cfg = cm.get_logging_config() + self.assertEqual(cfg['python']['root'], 'INFO') + self.assertEqual(cfg['python']['services']['network'], 'INFO') + self.assertEqual(cfg['containers']['caddy'], 'INFO') + self.assertEqual(cfg['containers']['coredns'], 'INFO') + + def test_set_and_get_python_level_round_trip(self): + cm = _make_cm(self.tmp) + cm.set_python_log_level('network', 'DEBUG') + cm.set_python_log_level('root', 'WARNING') + # Re-load from disk to prove persistence. + cm2 = _make_cm(self.tmp) + cfg = cm2.get_logging_config() + self.assertEqual(cfg['python']['services']['network'], 'DEBUG') + self.assertEqual(cfg['python']['root'], 'WARNING') + + def test_set_and_get_container_level_round_trip(self): + cm = _make_cm(self.tmp) + cm.set_container_log_level('coredns', 'DEBUG') + cm2 = _make_cm(self.tmp) + self.assertEqual(cm2.get_logging_config()['containers']['coredns'], 'DEBUG') + + def test_invalid_python_level_rejected(self): + cm = _make_cm(self.tmp) + with self.assertRaises(ValueError): + cm.set_python_log_level('network', 'LOUD') + + def test_invalid_container_level_rejected(self): + cm = _make_cm(self.tmp) + with self.assertRaises(ValueError): + cm.set_container_log_level('caddy', 'chatty') + + def test_migration_from_legacy_log_levels_json(self): + # Legacy side-file lived at config/api/log_levels.json (next to cell_config). + api_cfg_dir = os.path.join(self.tmp, 'api') + os.makedirs(api_cfg_dir, exist_ok=True) + with open(os.path.join(api_cfg_dir, 'log_levels.json'), 'w') as f: + json.dump({'network': 'DEBUG', 'email': 'WARNING', 'bogus': 'INFO'}, f) + cm = _make_cm(self.tmp) + cfg = cm.get_logging_config() + self.assertEqual(cfg['python']['services']['network'], 'DEBUG') + self.assertEqual(cfg['python']['services']['email'], 'WARNING') + # Unknown service names from the legacy file are ignored. + self.assertNotIn('bogus', cfg['python']['services']) + + def test_logging_section_is_part_of_persisted_config(self): + """The logging section lives in cell_config (already in the backup set).""" + cm = _make_cm(self.tmp) + cm.set_python_log_level('vault', 'ERROR') + with open(cm.config_file) as f: + on_disk = json.load(f) + self.assertIn('logging', on_disk) + self.assertEqual(on_disk['logging']['python']['services']['vault'], 'ERROR') + + +if __name__ == '__main__': + unittest.main() diff --git a/tests/test_logs_endpoints.py b/tests/test_logs_endpoints.py index a2811f9..8005875 100644 --- a/tests/test_logs_endpoints.py +++ b/tests/test_logs_endpoints.py @@ -79,6 +79,26 @@ class TestGetBackendLogs(unittest.TestCase): self.assertEqual(r.status_code, 500) self.assertIn('error', json.loads(r.data)) + def test_get_logs_level_filter_returns_only_matching(self): + lines = [ + json.dumps({'level': 'INFO', 'message': 'started'}) + '\n', + json.dumps({'level': 'ERROR', 'message': 'boom'}) + '\n', + json.dumps({'level': 'INFO', 'message': 'ok'}) + '\n', + json.dumps({'level': 'ERROR', 'message': 'kaboom'}) + '\n', + ] + m = mock_open(read_data=''.join(lines)) + m.return_value.readlines = lambda: lines + with patch('app.auth_manager', MagicMock(spec=object)), \ + patch('app.os.path.exists', return_value=True), \ + patch('builtins.open', m): + r = self.client.get('/api/logs?level=ERROR') + self.assertEqual(r.status_code, 200) + out = json.loads(r.data)['log'] + self.assertIn('boom', out) + self.assertIn('kaboom', out) + self.assertNotIn('started', out) + self.assertNotIn('"message": "ok"', out) + class TestGetServiceLogs(unittest.TestCase): """GET /api/logs/services/""" @@ -309,49 +329,86 @@ class TestLogVerbosity(unittest.TestCase): app.config['TESTING'] = True self.client = app.test_client() - @patch('app.log_manager') - def test_get_verbosity_returns_200_with_levels_map(self, mock_lm): - mock_lm.get_service_levels.return_value = { - 'dns': 'INFO', - 'email': 'DEBUG', - 'wireguard': 'WARNING', + @patch('app.config_manager') + def test_get_verbosity_returns_200_with_python_and_containers(self, mock_cm): + mock_cm.get_logging_config.return_value = { + 'python': {'root': 'INFO', 'services': {'email': 'DEBUG', 'wireguard': 'WARNING'}}, + 'containers': {'caddy': 'INFO', 'coredns': 'DEBUG'}, } r = self.client.get('/api/logs/verbosity') self.assertEqual(r.status_code, 200) data = json.loads(r.data) - self.assertIn('dns', data) - self.assertEqual(data['email'], 'DEBUG') + self.assertEqual(data['python']['services']['email'], 'DEBUG') + self.assertEqual(data['containers']['coredns'], 'DEBUG') - @patch('app.log_manager') - def test_get_verbosity_returns_500_on_exception(self, mock_lm): - mock_lm.get_service_levels.side_effect = Exception('config missing') + @patch('app.config_manager') + def test_get_verbosity_returns_500_on_exception(self, mock_cm): + mock_cm.get_logging_config.side_effect = Exception('config missing') r = self.client.get('/api/logs/verbosity') self.assertEqual(r.status_code, 500) self.assertIn('error', json.loads(r.data)) + @patch('app.apply_root_log_level') @patch('app.log_manager') - def test_put_verbosity_returns_200_and_calls_set_level(self, mock_lm): - mock_lm.get_service_levels.return_value = {'dns': 'DEBUG'} - with tempfile.TemporaryDirectory() as tmpdir: - with patch('app.auth_manager', MagicMock(spec=object)), \ - patch.dict('os.environ', {'CONFIG_DIR': tmpdir}): - r = self.client.put( - '/api/logs/verbosity', - data=json.dumps({'dns': 'DEBUG'}), - content_type='application/json', - ) + @patch('app.config_manager') + def test_put_verbosity_python_applies_hot(self, mock_cm, mock_lm, mock_apply): + mock_cm.get_logging_config.return_value = { + 'python': {'root': 'DEBUG', 'services': {'network': 'DEBUG'}}, + 'containers': {}, + } + with patch('app.auth_manager', MagicMock(spec=object)): + r = self.client.put( + '/api/logs/verbosity', + data=json.dumps({'python': {'root': 'DEBUG', 'services': {'network': 'DEBUG'}}}), + content_type='application/json', + ) self.assertEqual(r.status_code, 200) - mock_lm.set_service_level.assert_called_with('dns', 'DEBUG') + mock_cm.set_python_log_level.assert_any_call('network', 'DEBUG') + mock_cm.set_python_log_level.assert_any_call('root', 'DEBUG') + mock_lm.set_service_level.assert_called_with('network', 'DEBUG') + mock_apply.assert_called_with('DEBUG') - @patch('app.log_manager') - def test_put_verbosity_returns_500_on_exception(self, mock_lm): - mock_lm.set_service_level.side_effect = Exception('unknown service') - r = self.client.put( - '/api/logs/verbosity', - data=json.dumps({'unknown_svc': 'DEBUG'}), - content_type='application/json', - ) - self.assertEqual(r.status_code, 500) + @patch('app.firewall_manager') + @patch('app.config_manager') + def test_put_verbosity_coredns_applies_hot(self, mock_cm, mock_fw): + mock_cm.get_logging_config.return_value = {'python': {}, 'containers': {'coredns': 'DEBUG'}} + mock_cm.get_internal_domain.return_value = 'cell' + with patch('app.auth_manager', MagicMock(spec=object)), \ + patch('app.peer_registry', MagicMock(list_peers=lambda: [])), \ + patch('app.cell_link_manager', MagicMock(list_connections=lambda: None)): + r = self.client.put( + '/api/logs/verbosity', + data=json.dumps({'containers': {'coredns': 'DEBUG'}}), + content_type='application/json', + ) + self.assertEqual(r.status_code, 200) + data = json.loads(r.data) + self.assertEqual(data['applied']['coredns'], 'hot') + mock_fw.generate_corefile.assert_called_once() + mock_fw.reload_coredns.assert_called_once() + + @patch('app.config_manager') + def test_put_verbosity_wireguard_returns_pending_restart(self, mock_cm): + mock_cm.get_logging_config.return_value = {'python': {}, 'containers': {'wireguard': 'DEBUG'}} + with patch('app.auth_manager', MagicMock(spec=object)): + r = self.client.put( + '/api/logs/verbosity', + data=json.dumps({'containers': {'wireguard': 'DEBUG'}}), + content_type='application/json', + ) + self.assertEqual(r.status_code, 200) + self.assertEqual(json.loads(r.data)['applied']['wireguard'], 'pending_restart') + + @patch('app.config_manager') + def test_put_verbosity_invalid_level_returns_400(self, mock_cm): + mock_cm.set_python_log_level.side_effect = ValueError('Invalid log level') + with patch('app.auth_manager', MagicMock(spec=object)): + r = self.client.put( + '/api/logs/verbosity', + data=json.dumps({'python': {'services': {'network': 'LOUD'}}}), + content_type='application/json', + ) + self.assertEqual(r.status_code, 400) self.assertIn('error', json.loads(r.data)) diff --git a/tests/test_routes_services_catalog.py b/tests/test_routes_services_catalog.py index 91bb688..88c991e 100644 --- a/tests/test_routes_services_catalog.py +++ b/tests/test_routes_services_catalog.py @@ -616,25 +616,31 @@ class TestGetLogFiles: class TestGetLogVerbosity: def test_returns_200(self, client): - mock_lm = MagicMock() - mock_lm.get_service_levels.return_value = {'network': 'INFO'} - with patch.object(app_module, 'log_manager', mock_lm): + mock_cm = MagicMock() + mock_cm.get_logging_config.return_value = { + 'python': {'root': 'INFO', 'services': {'network': 'INFO'}}, + 'containers': {'caddy': 'INFO'}, + } + with patch.object(app_module, 'config_manager', mock_cm): resp = client.get('/api/logs/verbosity') assert resp.status_code == 200 - def test_returns_service_levels(self, client): - mock_lm = MagicMock() - mock_lm.get_service_levels.return_value = {'network': 'DEBUG', 'email': 'INFO'} - with patch.object(app_module, 'log_manager', mock_lm): + def test_returns_python_and_container_sections(self, client): + mock_cm = MagicMock() + mock_cm.get_logging_config.return_value = { + 'python': {'root': 'INFO', 'services': {'network': 'DEBUG', 'email': 'INFO'}}, + 'containers': {'caddy': 'WARNING'}, + } + with patch.object(app_module, 'config_manager', mock_cm): resp = client.get('/api/logs/verbosity') data = json.loads(resp.data) - assert data['network'] == 'DEBUG' - assert data['email'] == 'INFO' + assert data['python']['services']['network'] == 'DEBUG' + assert data['containers']['caddy'] == 'WARNING' def test_500_on_exception(self, client): - mock_lm = MagicMock() - mock_lm.get_service_levels.side_effect = Exception('fail') - with patch.object(app_module, 'log_manager', mock_lm): + mock_cm = MagicMock() + mock_cm.get_logging_config.side_effect = Exception('fail') + with patch.object(app_module, 'config_manager', mock_cm): resp = client.get('/api/logs/verbosity') assert resp.status_code == 500 @@ -645,36 +651,37 @@ class TestGetLogVerbosity: class TestSetLogVerbosity: def test_returns_200(self, client): - import tempfile, os - mock_lm = MagicMock() - mock_lm.set_service_level.return_value = None - mock_lm.get_service_levels.return_value = {'network': 'DEBUG'} - with patch.object(app_module, 'log_manager', mock_lm): - with tempfile.TemporaryDirectory() as tmpdir: - with patch.dict(os.environ, {'CONFIG_DIR': tmpdir}): - resp = client.put('/api/logs/verbosity', - data=json.dumps({'network': 'DEBUG'}), - content_type='application/json') + mock_cm = MagicMock() + mock_cm.get_logging_config.return_value = { + 'python': {'root': 'INFO', 'services': {'network': 'DEBUG'}}, + 'containers': {}, + } + with patch.object(app_module, 'config_manager', mock_cm), \ + patch.object(app_module, 'log_manager', MagicMock()): + resp = client.put('/api/logs/verbosity', + data=json.dumps({'python': {'services': {'network': 'DEBUG'}}}), + content_type='application/json') assert resp.status_code == 200 - def test_calls_set_service_level(self, client): - import tempfile, os + def test_persists_via_config_manager_and_applies_hot(self, client): + mock_cm = MagicMock() + mock_cm.get_logging_config.return_value = {'python': {}, 'containers': {}} mock_lm = MagicMock() - mock_lm.get_service_levels.return_value = {} - with patch.object(app_module, 'log_manager', mock_lm): - with tempfile.TemporaryDirectory() as tmpdir: - with patch.dict(os.environ, {'CONFIG_DIR': tmpdir}): - client.put('/api/logs/verbosity', - data=json.dumps({'network': 'DEBUG'}), - content_type='application/json') + with patch.object(app_module, 'config_manager', mock_cm), \ + patch.object(app_module, 'log_manager', mock_lm): + client.put('/api/logs/verbosity', + data=json.dumps({'python': {'services': {'network': 'DEBUG'}}}), + content_type='application/json') + mock_cm.set_python_log_level.assert_called_with('network', 'DEBUG') mock_lm.set_service_level.assert_called_with('network', 'DEBUG') def test_500_on_exception(self, client): - mock_lm = MagicMock() - mock_lm.set_service_level.side_effect = Exception('fail') - with patch.object(app_module, 'log_manager', mock_lm): + mock_cm = MagicMock() + mock_cm.set_python_log_level.side_effect = Exception('fail') + with patch.object(app_module, 'config_manager', mock_cm), \ + patch.object(app_module, 'log_manager', MagicMock()): resp = client.put('/api/logs/verbosity', - data=json.dumps({'network': 'DEBUG'}), + data=json.dumps({'python': {'services': {'network': 'DEBUG'}}}), content_type='application/json') assert resp.status_code == 500 diff --git a/webui/src/pages/Logs.jsx b/webui/src/pages/Logs.jsx index 7f3e080..5fa38c3 100644 --- a/webui/src/pages/Logs.jsx +++ b/webui/src/pages/Logs.jsx @@ -260,9 +260,38 @@ function ContainerLogsTab() { } // ── Tab 3: Verbosity Config ───────────────────────────────────────────────── +const VERBOSITY_LEVELS = ['DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL']; +// Container services that need a container recreate before a level change applies. +const PENDING_RESTART_CONTAINERS = ['wireguard', 'mailserver']; + +function LevelRow({ name, value, original, badge, onChange }) { + return ( + + + {name} + {badge && ( + + needs restart + + )} + + + + {value !== original && changed} + + + ); +} + function VerbosityTab() { - const [levels, setLevels] = useState({}); - const [pending, setPending] = useState({}); + const [config, setConfig] = useState(null); // last-saved server state + const [pending, setPending] = useState(null); // editable copy const [loading, setLoading] = useState(false); const [saving, setSaving] = useState(false); const [msg, setMsg] = useState(''); @@ -271,8 +300,8 @@ function VerbosityTab() { setLoading(true); try { const res = await logsAPI.getVerbosity(); - setLevels(res.data || {}); - setPending(res.data || {}); + setConfig(res.data); + setPending(JSON.parse(JSON.stringify(res.data))); } catch (e) { setMsg(`Error: ${e.message}`); } finally { @@ -282,34 +311,46 @@ function VerbosityTab() { useEffect(() => { load(); }, []); + const setRoot = (v) => + setPending(p => ({ ...p, python: { ...p.python, root: v } })); + const setService = (svc, v) => + setPending(p => ({ ...p, python: { ...p.python, services: { ...p.python.services, [svc]: v } } })); + const setContainer = (c, v) => + setPending(p => ({ ...p, containers: { ...p.containers, [c]: v } })); + const save = async () => { - const changed = Object.fromEntries( - Object.entries(pending).filter(([k, v]) => v !== levels[k]) - ); - if (!Object.keys(changed).length) { setMsg('No changes.'); return; } setSaving(true); setMsg(''); try { - const res = await logsAPI.setVerbosity(changed); - setLevels(res.data.levels || pending); - setMsg('Levels saved and applied.'); + const res = await logsAPI.setVerbosity(pending); + setConfig(res.data.logging); + setPending(JSON.parse(JSON.stringify(res.data.logging))); + const restarts = Object.entries(res.data.applied || {}) + .filter(([, v]) => v === 'pending_restart') + .map(([k]) => k); + setMsg(restarts.length + ? `Saved. ${restarts.join(', ')} will apply on next container restart.` + : 'Levels saved and applied.'); } catch (e) { - setMsg(`Error: ${e.message}`); + setMsg(`Error: ${e.response?.data?.error || e.message}`); } finally { setSaving(false); } }; - const services = Object.keys(pending).sort(); + if (loading || !pending) return
Loading…
; + + const services = Object.keys(pending.python.services).sort(); + const containers = Object.keys(pending.containers).sort(); return ( -
-
- Changes apply immediately to the running API — no restart needed. Levels are persisted to - config/log_levels.json and restored on container restart. -
- - {loading ?
Loading…
: ( +
+
+

Python services

+
+ Applies immediately to the running API — no restart needed. Persisted in cell_config and + restored on restart. +
@@ -318,28 +359,52 @@ function VerbosityTab() { + {services.map(svc => ( - - - - + setService(svc, v)} + /> ))}
{svc} - - {pending[svc] !== levels[svc] && ( - changed - )} -
- )} +
+ +
+

Container services

+
+ caddy and coredns reload immediately. wireguard and mailserver are container-ENV driven — + their level applies on the next container restart. +
+ + + + + + + + + {containers.map(c => ( + setContainer(c, v)} + /> + ))} + +
ContainerLog Level
+