From a1df3fa75cebacd303959647211fc7d6587a0469 Mon Sep 17 00:00:00 2001 From: sysangels | Michal Koeckeis-Fresel Date: Tue, 10 Mar 2026 13:31:45 +0100 Subject: [PATCH 1/4] Scheduler config saver failures and manual plugin handling issues with poor observability #3303 Scheduler config saver failures and manual plugin handling issues with poor observability #3303 --- src/common/db/Database.py | 39 ++++++++++++++++++++- src/scheduler/main.py | 66 ++++++++++++++++++++++++++++++++++-- src/ui/app/dependencies.py | 53 ++++++++++++++++++++++++----- src/ui/app/routes/plugins.py | 8 +++-- 4 files changed, 151 insertions(+), 15 deletions(-) diff --git a/src/common/db/Database.py b/src/common/db/Database.py index 4ad12cb01e..0802b55e72 100644 --- a/src/common/db/Database.py +++ b/src/common/db/Database.py @@ -8,7 +8,7 @@ from functools import wraps from io import BytesIO from json import JSONDecodeError, loads -from logging import Logger +from logging import Logger, WARNING, getLogger from os import _exit, getenv, sep from os.path import join as os_join from pathlib import Path @@ -233,6 +233,14 @@ def validate_and_update_db_string(db_string: str) -> Tuple[str, Optional[Match]] "pool_timeout": 5, } | kwargs + # Unless explicitly requested via SQLALCHEMY_LOG_LEVEL, keep SQLAlchemy's own + # loggers quiet (WARNING+) so they don't flood BunkerWeb logs with internal + # mapper/engine configuration chatter. + sqlalchemy_log_level = getenv("SQLALCHEMY_LOG_LEVEL", "").upper() + if sqlalchemy_log_level not in {"DEBUG", "INFO"}: + for name in ("sqlalchemy", "sqlalchemy.engine", "sqlalchemy.orm", "sqlalchemy.pool"): + getLogger(name).setLevel(WARNING) + try: self.sql_engine = create_engine(sqlalchemy_string, **self._engine_kwargs) except ArgumentError: @@ -3142,6 +3150,22 @@ def _add_ordered(items: List[Any]) -> None: commands = plugin.pop("bwcli", {}) if not isinstance(commands, dict): commands = {} + + # Validate settings before importing the plugin into the database. + # This helps catch mistakes in plugin.json early (especially missing "regex" + # on settings, which would otherwise violate the NOT NULL constraint on + # bw_settings.regex). We keep the import logic tolerant (it will still + # default missing regex values), but emit a clear, actionable log so that + # users can fix their plugin definitions. + missing_regex = [name for name, value in settings.items() if not value.get("regex")] + if missing_regex: + self.logger.error( + f'Plugin "{plugin.get("id", "")}" has settings without a "regex" field: ' + f'{", ".join(missing_regex)}. Please add a non-empty "regex" to each of those ' + "settings in plugin.json. You can list such settings on your system with a command like:\n" + "jq '.settings | to_entries[] | select(.value.regex == null or .value.regex == \"\" ) | .key' " + f"/etc/bunkerweb/plugins/{plugin.get('id', '')}/plugin.json" + ) plugin["type"] = _type db_plugin = ( session.query(Plugins) @@ -3215,6 +3239,13 @@ def _add_ordered(items: List[Any]) -> None: plugin_settings = set() for setting, value in settings.items(): value.update({"plugin_id": plugin["id"], "name": value["id"], "id": setting}) + # Ensure we always have a non-null regex for settings. Some external plugins + # may omit the "regex" field in their plugin.json; however, the database + # enforces a NOT NULL constraint on bw_settings.regex. Default to a very + # permissive pattern in that case so that those plugins can still be + # imported and managed via the UI. + if not value.get("regex"): + value["regex"] = "^.*$" plugin_settings.add(setting) db_setting = ( @@ -3782,6 +3813,12 @@ def _add_ordered(items: List[Any]) -> None: continue value.update({"plugin_id": plugin["id"], "name": value["id"], "id": setting}) + # Ensure we always have a non-null regex for settings when inserting a new plugin. + # This mirrors the behavior in the update path above so that external plugins whose + # plugin.json omit the "regex" field can still be imported without violating the + # NOT NULL constraint on bw_settings.regex. + if not value.get("regex"): + value["regex"] = "^.*$" for sel_order, select in enumerate(value.pop("select", []), start=1): local_to_put.append(Selects(setting_id=value["id"], value=self._empty_if_none(select), order=sel_order)) diff --git a/src/scheduler/main.py b/src/scheduler/main.py index 50742e70d9..d1874370b2 100644 --- a/src/scheduler/main.py +++ b/src/scheduler/main.py @@ -14,7 +14,7 @@ from shutil import copy, rmtree, copytree from signal import SIGINT, SIGTERM, signal, SIGHUP from stat import S_IRGRP, S_IRUSR, S_IWUSR, S_IXGRP, S_IXUSR -from subprocess import run as subprocess_run, DEVNULL, STDOUT +from subprocess import run as subprocess_run, DEVNULL, STDOUT, PIPE from sys import path as sys_path from tarfile import TarFile, open as tar_open from threading import Event, Lock @@ -186,12 +186,23 @@ def handle_reload(signum, frame): join(sep, "etc", "bunkerweb", "variables.env"), ], stdin=DEVNULL, + stdout=PIPE, stderr=STDOUT, + text=True, check=False, env=cmd_env, ) if proc.returncode != 0: + # Keep the legacy one-line error for existing log parsers, + # then emit a second line with detailed diagnostics. LOGGER.error("Config saver failed, configuration will not work as expected...") + output = (proc.stdout or "").strip() + if len(output) > 8000: + output = output[:8000] + "... [truncated]" + LOGGER.error( + "Config saver failed, configuration will not work as expected... " + f"returncode={proc.returncode}, args={proc.args!r}, output={output!r}" + ) else: LOGGER.warning("Ignored reload operation because scheduler is not running ...") except BaseException as e: @@ -321,6 +332,14 @@ def generate_external_plugins(original_path: Union[Path, str] = EXTERNAL_PLUGINS with suppress(StopIteration, IndexError, FileNotFoundError): index = next(i for i, plugin in enumerate(plugins) if plugin["id"] == file.name) + # For manually managed external plugins, the on-disk folder is the source of truth. + # Never delete or overwrite them from the database – they will be pushed *to* the DB + # by check_plugin_changes() when their checksum/version changes. + if not pro and plugins[index].get("method") == "manual": + LOGGER.debug(f"Skipping removal of manually managed external plugin directory {file} (method=manual)") + ignored_plugins.add(file.name) + continue + with BytesIO() as plugin_content: with tar_open(fileobj=plugin_content, mode="w:gz", compresslevel=9) as tar: if file.is_dir(): @@ -727,12 +746,23 @@ def backup_failover(): env_file_path.as_posix(), ], stdin=DEVNULL, + stdout=PIPE, stderr=STDOUT, + text=True, check=False, env=cmd_env, ) if proc.returncode != 0: + # Keep the legacy one-line error for existing log parsers, + # then emit a second line with detailed diagnostics. LOGGER.error("Config saver failed, configuration will not work as expected...") + output = (proc.stdout or "").strip() + if len(output) > 8000: + output = output[:8000] + "... [truncated]" + LOGGER.error( + "Config saver failed, configuration will not work as expected... " + f"returncode={proc.returncode}, args={proc.args!r}, output={output!r}" + ) ready = False while not ready: @@ -801,12 +831,23 @@ def run_config_saver(log_message: str) -> bool: env_file_path.as_posix(), ], stdin=DEVNULL, + stdout=PIPE, stderr=STDOUT, + text=True, check=False, env=cmd_env, ) if proc.returncode != 0: + # Keep the legacy one-line error for existing log parsers, + # then emit a second line with detailed diagnostics. LOGGER.error("Config saver failed, configuration will not work as expected...") + output = (proc.stdout or "").strip() + if len(output) > 8000: + output = output[:8000] + "... [truncated]" + LOGGER.error( + "Config saver failed, configuration will not work as expected... " + f"returncode={proc.returncode}, args={proc.args!r}, output={output!r}" + ) return False return True @@ -886,8 +927,27 @@ def check_plugin_changes(_type: Literal["external", "pro"] = "external"): with suppress(StopIteration, IndexError): index = next(i for i, plugin in enumerate(db_plugins) if plugin["id"] == common_data["id"]) - if checksum == db_plugins[index]["checksum"] or db_plugins[index]["method"] != "manual": - continue + disk_version = common_data.get("version", "") + db_version = db_plugins[index].get("version", "") + + if disk_version != db_version: + LOGGER.warning( + f"Version mismatch detected for {_type} plugin {common_data['id']}: " + f"plugin.json={disk_version!r}, database={db_version!r} – treating as changed" + ) + else: + # No version change: for external plugins, keep the on-disk plugin.json/data + # as source of truth and only treat it as changed if the checksum differs. + # For pro plugins, we also require method == "manual" before we allow the + # on-disk plugin to override what is stored in the database. + if _type == "external": + if checksum == db_plugins[index]["checksum"]: + continue + else: + # Pro plugin: skip if checksum is unchanged or the existing DB entry + # is not marked as manually managed (method != "manual"). + if checksum == db_plugins[index]["checksum"] or db_plugins[index]["method"] != "manual": + continue tmp_external_plugins.append(common_data.copy()) diff --git a/src/ui/app/dependencies.py b/src/ui/app/dependencies.py index 288da804e9..02824a1ff4 100644 --- a/src/ui/app/dependencies.py +++ b/src/ui/app/dependencies.py @@ -8,6 +8,7 @@ from stat import S_IRGRP, S_IRUSR, S_IWUSR, S_IXGRP, S_IXUSR from tarfile import open as tar_open from traceback import format_exc +import json from common_utils import bytes_hash # type: ignore @@ -48,6 +49,15 @@ def reload_plugins(): target = plugin_path / plugin["id"] + # For manually managed external plugins, the on-disk folder is the source of truth. + # Do not delete or overwrite them from the UI side – they are synchronized to the + # database by the scheduler's check_plugin_changes() logic instead. + if plugin["type"] == "external" and plugin.get("method") == "manual": + if target.exists(): + DB.logger.debug(f"Skipping reload of manually managed external plugin directory {target} (method=manual)") + ignored_plugins.add(plugin["id"]) + continue + # If the target exists, compare its checksum. if target.exists(): with suppress(StopIteration, IndexError, FileNotFoundError): @@ -66,6 +76,10 @@ def reload_plugins(): elif target.is_dir(): rmtree(target, ignore_errors=True) + # If this plugin was marked as ignored (same checksum or manually managed), do not re-extract. + if plugin["id"] in ignored_plugins: + continue + try: if plugin["data"]: with tar_open(fileobj=BytesIO(plugin["data"]), mode="r:gz") as tar: @@ -98,16 +112,37 @@ def reload_plugins(): DB.logger.error(f"An error occurred when setting the changes to checked in the database : {ret}") # Cleanup: Remove plugin folders that exist on the filesystem but are not in the database. + # For manually managed external plugins (method=manual in plugin.json), keep the on-disk + # folder even if the database does not yet know about the plugin. The scheduler will + # reconcile those via check_plugin_changes(). for plugin_path in (EXTERNAL_PLUGINS_PATH, PRO_PLUGINS_PATH): - if plugin_path.exists(): - for item in plugin_path.iterdir(): - if item.name not in known_plugin_ids: - DB.logger.debug(f"Plugin {item.name} not found in database, removing it...") - with suppress(OSError): - if item.is_symlink() or item.is_file(): - item.unlink() - elif item.is_dir(): - rmtree(item, ignore_errors=True) + if not plugin_path.exists(): + continue + + for item in plugin_path.iterdir(): + # Skip known plugins that are present in the database. + if item.name in known_plugin_ids: + continue + + # For external plugins, preserve manually managed ones based on plugin.json metadata. + if plugin_path == EXTERNAL_PLUGINS_PATH and item.is_dir(): + plugin_json = item / "plugin.json" + if plugin_json.exists(): + try: + with plugin_json.open("r", encoding="utf-8") as f: + plugin_meta = json.load(f) + if plugin_meta.get("method") == "manual": + DB.logger.debug(f"Preserving manually managed external plugin directory {item} (method=manual, not yet in database)") + continue + except Exception: # noqa: BLE001 + DB.logger.debug(f"Failed to inspect {plugin_json} while cleaning up plugins:\n{format_exc()}") + + DB.logger.debug(f"Plugin {item.name} not found in database, removing it...") + with suppress(OSError): + if item.is_symlink() or item.is_file(): + item.unlink() + elif item.is_dir(): + rmtree(item, ignore_errors=True) def safe_reload_plugins(force: bool = False): diff --git a/src/ui/app/routes/plugins.py b/src/ui/app/routes/plugins.py index eea0f9ffa0..8f326f9c41 100644 --- a/src/ui/app/routes/plugins.py +++ b/src/ui/app/routes/plugins.py @@ -604,8 +604,12 @@ def plugin_used(prefix: str = "") -> bool: """ try: - # Merge globals and ENV with ENV taking precedence - template_vars = {**current_app.jinja_env.globals, **current_app.config["ENV"]} + # Merge globals and ENV with ENV taking precedence. + # Be defensive in case ENV is not yet initialized in app.config. + env_data = current_app.config.get("ENV") or {} + if not isinstance(env_data, dict): + env_data = {} + template_vars = {**current_app.jinja_env.globals, **env_data} # deepcode ignore Ssti: We trust the plugin template plugin_page = ( From f72fae80e8e0d148bdb6025458ed3281f17bb978 Mon Sep 17 00:00:00 2001 From: sysangels | Michal Koeckeis-Fresel Date: Tue, 10 Mar 2026 13:39:23 +0100 Subject: [PATCH 2/4] fix conflicts --- src/common/db/Database.py | 14 ++++++++++++++ 1 file changed, 14 insertions(+) diff --git a/src/common/db/Database.py b/src/common/db/Database.py index 0802b55e72..aa3e30fd2a 100644 --- a/src/common/db/Database.py +++ b/src/common/db/Database.py @@ -233,6 +233,20 @@ def validate_and_update_db_string(db_string: str) -> Tuple[str, Optional[Match]] "pool_timeout": 5, } | kwargs + # Configure pool_reset_on_return unless explicitly overridden in kwargs. + if "pool_reset_on_return" not in kwargs: + default_pool_reset = "rollback" + configured_pool_reset = getenv("DATABASE_POOL_RESET_ON_RETURN", "").strip().lower() or default_pool_reset + if configured_pool_reset in ("none", "null", "off", "false", "no"): + self._engine_kwargs["pool_reset_on_return"] = None + elif configured_pool_reset in ("rollback", "commit"): + self._engine_kwargs["pool_reset_on_return"] = configured_pool_reset + else: + self.logger.warning( + f"Invalid DATABASE_POOL_RESET_ON_RETURN value: {configured_pool_reset}, using default value ({default_pool_reset})" + ) + self._engine_kwargs["pool_reset_on_return"] = default_pool_reset + # Unless explicitly requested via SQLALCHEMY_LOG_LEVEL, keep SQLAlchemy's own # loggers quiet (WARNING+) so they don't flood BunkerWeb logs with internal # mapper/engine configuration chatter. From 30a22830b00515f4738bcf188b5a46fbeb14364c Mon Sep 17 00:00:00 2001 From: sysangels | Michal Koeckeis-Fresel Date: Tue, 10 Mar 2026 14:37:14 +0100 Subject: [PATCH 3/4] don't fail the whole config saver run; just warn and skip. --- src/common/db/Database.py | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-) diff --git a/src/common/db/Database.py b/src/common/db/Database.py index aa3e30fd2a..34a75df1dd 100644 --- a/src/common/db/Database.py +++ b/src/common/db/Database.py @@ -956,7 +956,16 @@ def init_tables(self, default_plugins: List[dict]) -> Tuple[bool, str]: if path_ui.is_dir(): with BytesIO() as plugin_page_content: with tar_open(fileobj=plugin_page_content, mode="w:gz", compresslevel=9) as tar: - tar.add(path_ui, arcname=path_ui.name, recursive=True) + try: + tar.add(path_ui, arcname=path_ui.name, recursive=True) + except FileNotFoundError as e: + # If some files disappeared between discovery and archiving + # (for example, partially removed or obfuscated UI files), + # don't fail the whole config saver run; just warn and skip. + self.logger.warning( + f"Skipping missing file while archiving UI for plugin '{base_plugin['id']}': {e}" + ) + continue plugin_page_content.seek(0) checksum = bytes_hash(plugin_page_content, algorithm="sha256") desired_plugin_pages[base_plugin["id"]] = { From 1003071e9aec6aa42ce8b69423b4ada674b38e2c Mon Sep 17 00:00:00 2001 From: sysangels | Michal Koeckeis-Fresel Date: Tue, 10 Mar 2026 14:56:30 +0100 Subject: [PATCH 4/4] truncating was too small - missed the error message --- src/scheduler/main.py | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/src/scheduler/main.py b/src/scheduler/main.py index d1874370b2..e04d3f4ad1 100644 --- a/src/scheduler/main.py +++ b/src/scheduler/main.py @@ -197,8 +197,8 @@ def handle_reload(signum, frame): # then emit a second line with detailed diagnostics. LOGGER.error("Config saver failed, configuration will not work as expected...") output = (proc.stdout or "").strip() - if len(output) > 8000: - output = output[:8000] + "... [truncated]" + if len(output) > 64000: + output = output[:64000] + "... [truncated]" LOGGER.error( "Config saver failed, configuration will not work as expected... " f"returncode={proc.returncode}, args={proc.args!r}, output={output!r}" @@ -757,8 +757,8 @@ def backup_failover(): # then emit a second line with detailed diagnostics. LOGGER.error("Config saver failed, configuration will not work as expected...") output = (proc.stdout or "").strip() - if len(output) > 8000: - output = output[:8000] + "... [truncated]" + if len(output) > 64000: + output = output[:64000] + "... [truncated]" LOGGER.error( "Config saver failed, configuration will not work as expected... " f"returncode={proc.returncode}, args={proc.args!r}, output={output!r}" @@ -842,8 +842,8 @@ def run_config_saver(log_message: str) -> bool: # then emit a second line with detailed diagnostics. LOGGER.error("Config saver failed, configuration will not work as expected...") output = (proc.stdout or "").strip() - if len(output) > 8000: - output = output[:8000] + "... [truncated]" + if len(output) > 64000: + output = output[:64000] + "... [truncated]" LOGGER.error( "Config saver failed, configuration will not work as expected... " f"returncode={proc.returncode}, args={proc.args!r}, output={output!r}"