Scheduler config saver failures and manual plugin handling issues with poor observability #3303

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,28 @@ 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.
+        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:
@@ -934,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"]] = {
@@ -3142,6 +3173,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", "<unknown>")}" 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-id>')}/plugin.json"
+                    )
                 plugin["type"] = _type
                 db_plugin = (
                     session.query(Plugins)
@@ -3215,6 +3262,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 +3836,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))

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) > 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}"
+                )
         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) > 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}"
+                )
 
         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) > 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}"
+                )
                 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())
 

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):

src/ui/app/routes/plugins.py

@@ -604,8 +604,12 @@ def plugin_used(prefix: str = "") -> bool:
 </div>"""
 
             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 = (