Browse Source

fix(db): cap SQLite pool fd bill + raise container nofile — prevents fd-exhaustion DB corruption (#2884)

M2ABRAMSTANK 1 day ago
parent
commit
3ce9b917cb

+ 1 - 0
CHANGELOG.md

@@ -72,6 +72,7 @@ All notable changes to Bambuddy will be documented in this file.
 - **The frontend build no longer warns about `path` and `crypto` being externalized for the STEP previewer (#2976)** — `occt-import-js`, the Emscripten build behind STEP previews, requires both modules, but only inside its `ENVIRONMENT_IS_NODE` branches; in the browser it loads its `.wasm` from the URL the preview worker passes and draws randomness from `crypto.getRandomValues`. Vite still externalized both and printed two warnings on every build. `vite.config.ts` now drops exactly those two warnings for that one package through `build.rolldownOptions.onLog`, so an externalization anywhere else, or of any other module, still shows.
 
 ### Fixed
+- **Running out of file descriptors could corrupt a SQLite database (#2883, reported and contributed by @M2ABRAMSTANK in #2884)** — Docker, the systemd service and most native installs start Bambuddy with a limit of 1024 open files. Once a busy instance used them all, every new database connection failed with "disk I/O error"; on the reporter's single-printer install that went on for 44 hours and ended with "database disk image is malformed" and a login outage. Part of the reason is how SQLite works in WAL mode: a database connection that closes keeps its file open until the last connection closes, so the database's share of open files stays at the most connections the pool ever reached. Bambuddy now raises its own open-file limit to the maximum the system allows when it starts, on every install, and logs what it set. The SQLite connection pool is smaller (10 + 90 instead of 20 + 200), which halves its share. A large printer farm still on SQLite that runs out of connections can raise `DB_MAX_OVERFLOW`, but is better served by PostgreSQL. The support bundle now counts open files by kind (database, sockets, pipes and so on) against the limit, so the next report shows what is holding them. Covered by backend tests.
 - **One model queued to several printers could print in the wrong filament (#2799, reported and contributed by @grolmus in #2803)** — An AMS mapping is a list of one printer's own tray numbers, and Bambuddy stamped the mapping it worked out for the first selected printer onto every other printer in the same dispatch. Where those printers hold the same spools in a different slot order the tray numbers still resolve, so nothing looks wrong, and each copy prints from whatever sits in that tray — in the reported case ASA where the 3MF requires PETG. An explicit mapping also bypasses the printer's own filament-type check, so nothing further down catches it. Every selected printer is now mapped against its own AMS, and a mapping already stored on a queue item is checked against the printer about to run it and recomputed when it does not fit, which covers a spool moved between queueing and dispatch as well. A tray of the right type in the wrong colour is still accepted, as it always was when nothing better is loaded. A slot you put on a tray of another material yourself in the print dialog is kept as you chose it.
 - **A job whose filament is not loaded waits instead of printing (#2799, reported and contributed by @grolmus in #2803)** — When a slot the plate prints cannot be matched to a tray on the printer it is about to go to, the job is held for a manual start and the queue row says which filament it needs, the same way a job short of filament already waits. This also catches a job that matched nothing at all: it used to be sent anyway and refused by the printer after the whole file had been uploaded, with `0700_8012 Failed to get AMS mapping table` and no explanation on screen. A job queued to a model rather than a named printer gives its printer back when it is held, so pressing start lets the queue choose among all printers of that model again instead of tying the job to the one that could not run it. That choice still goes by filament type only, so when the filament is on the wrong nozzle or the AMS changed after the printer was picked, it can pick the same printer and hold the job there again. A held job waits for someone to press start even once the right spool is loaded, as the filament-shortage hold already does. Start then finds the spool and the job prints, keeping any trays already chosen for its other slots. If the filament is still not loaded, Start says which one is missing and offers Print Anyway, which sends the job the way it went out before this change. The filament named on the queue row and in the notification is in English whatever the interface language.
 - **SpoolBuddy recognises a Bambu Lab spool from either of its two tags, and finds the spool the AMS already created (#984, block 9 read from @Keybored02's #1200, measured by @Thomansky and @Sawtaytoes)** — A Bambu Lab spool has a tag on each side. The two have different tag UIDs, but share one spool ID, the same one the AMS reports. SpoolBuddy read that ID from the wrong part of the tag: the bytes it used hold the filament type, so every "PLA Matte" spool sent the same "ID". The kiosk then didn't save it, so a spool was only known by the UID of the tag that was scanned. Scanning the other side offered to add the spool again, and a spool added on the kiosk was not matched when it went into the AMS, and the other way round.

+ 67 - 0
backend/app/api/routes/support.py

@@ -365,6 +365,7 @@ def _collect_process_info() -> dict:
         out["connections"] = len(proc.net_connections(kind="inet"))
     except Exception:
         pass
+    out.update(_collect_fd_info(proc))
 
     # Children by executable name only. The count per name is what identifies a
     # leak; the arguments would leak credentials.
@@ -411,6 +412,72 @@ def _collect_process_info() -> dict:
     return out
 
 
+def _fd_kind(target: str) -> str:
+    """What an open descriptor points at, without saying where (#2883)."""
+    for prefix, kind in (("socket:", "socket"), ("pipe:", "pipe"), ("anon_inode:", "anon_inode")):
+        if target.startswith(prefix):
+            return kind
+    if target.endswith(".db"):
+        return "database"
+    if target.endswith(".db-wal"):
+        return "database_wal"
+    if target.endswith(".db-shm"):
+        return "database_shm"
+    if target.startswith("/dev/"):
+        return "device"
+    return "file"
+
+
+def _collect_fd_info(proc) -> dict:
+    """Descriptors in use, by kind, against the limit (#2883).
+
+    #2883 ran out of descriptors at a 1024 limit, and the SQLite pool could
+    account for only part of that. Nobody could say what held the rest, because
+    a bundle carried no count. ``fds_by_type`` answers it from the next report:
+    database, -wal and -shm separately (WAL keeps a closed connection's db fd
+    open), sockets, pipes and everything else. Kinds only, never paths. Linux
+    only for the breakdown; best-effort throughout.
+    """
+    import os
+
+    out: dict = {}
+    try:
+        out["num_fds"] = proc.num_fds()
+    except Exception:
+        pass
+    try:
+        import resource
+
+        soft, hard = resource.getrlimit(resource.RLIMIT_NOFILE)
+        infinity = resource.RLIM_INFINITY
+        out["fd_limit"] = {
+            "soft": "unlimited" if soft == infinity else soft,
+            "hard": "unlimited" if hard == infinity else hard,
+        }
+    except Exception:
+        pass
+    try:
+        from backend.app.core import fd_limit
+
+        if fd_limit.startup_status is not None:
+            out["fd_limit_at_startup"] = dict(fd_limit.startup_status)
+    except Exception:
+        pass
+    try:
+        kinds: dict[str, int] = {}
+        for name in os.listdir("/proc/self/fd"):
+            try:
+                kind = _fd_kind(os.readlink(f"/proc/self/fd/{name}"))
+            except OSError:
+                # Closed between listing and reading, which is normal.
+                continue
+            kinds[kind] = kinds.get(kind, 0) + 1
+        out["fds_by_type"] = dict(sorted(kinds.items(), key=lambda kv: -kv[1]))
+    except Exception:
+        pass
+    return out
+
+
 def _format_bytes(size_bytes: int) -> str:
     """Format bytes into human-readable string."""
     if size_bytes < 1024:

+ 3 - 1
backend/app/core/config.py

@@ -75,9 +75,11 @@ class Settings(BaseSettings):
     database_url: str = _external_db_url or f"sqlite+aiosqlite:///{_db_path}"
 
     # Database connection pool sizing. ``None`` = use the built-in, dialect-aware
-    # default (PostgreSQL: pool_size 20 + max_overflow 60; SQLite: 20 + 200).
+    # default (PostgreSQL: pool_size 20 + max_overflow 60; SQLite: 10 + 90).
     # Large PostgreSQL printer farms can raise these via the DB_POOL_SIZE /
     # DB_MAX_OVERFLOW / DB_POOL_TIMEOUT / DB_POOL_RECYCLE env vars (issue #2572).
+    # A large farm still on SQLite can raise DB_MAX_OVERFLOW, but is better
+    # served by moving to PostgreSQL (#2883).
     # Make sure PostgreSQL ``max_connections`` comfortably exceeds
     # (pool_size + max_overflow) x number of app worker processes.
     db_pool_size: int | None = Field(default=None, gt=0)

+ 32 - 4
backend/app/core/database.py

@@ -43,12 +43,40 @@ def _resolve_pool_kwargs() -> dict:
         farms while printer callbacks held connections. The 80-connection
         ceiling fits a stock server (max_connections 100, 3 reserved for
         superusers); 20 + 80 did not, and tripped the startup pool check.
-      - SQLite: pool_size 20 + max_overflow 200 (unchanged); no pre-ping /
-        recycle — the connection is a local file, not a server socket.
+      - SQLite: pool_size 10 + max_overflow 90 (lowered from 20 + 200, #2883 —
+        see the comment below); no pre-ping / recycle — the connection is a
+        local file, not a server socket.
     """
     if is_sqlite():
-        pool_size = settings.db_pool_size if settings.db_pool_size is not None else 20
-        max_overflow = settings.db_max_overflow if settings.db_max_overflow is not None else 200
+        # SQLite + WAL parks one main-db file descriptor per *closed* overflow
+        # connection: as long as any pooled connection stays open (it always
+        # does), SQLite's unix VFS moves the fd of every closing connection to
+        # its per-inode "unused fd" list instead of close(2)-ing it, to avoid
+        # the POSIX close-drops-advisory-locks trap. Those fds are reused by
+        # later connections but only released when the LAST connection to the
+        # file closes, which in a running server is effectively never. So the
+        # pool's database fds stay at the PEAK concurrency it ever reached.
+        #
+        # An open connection holds two fds (db and -wal; the -shm fd is shared
+        # per file), a parked one holds one. At the old 20 + 200 that is up to
+        # ~441 fds with every connection open and ~221 parked once they close.
+        # That alone does not reach Docker's default 1024 soft nofile; in
+        # #2883 other descriptors made up the rest. But it is the largest
+        # single share, and once the process hits EMFILE every new connection
+        # fails with "disk I/O error" (the WAL/shm open in the connect-time
+        # PRAGMAs), which in #2883 ran for 44h and ended in "database disk
+        # image is malformed". 10 + 90 halves the pool's share (~201 / ~101).
+        # The startup RLIMIT_NOFILE raise in main.py is the other half of the
+        # fix: it lifts the 1024 ceiling itself on every install.
+        #
+        # 20 + 200 came in with b8fa2df36 (March 2026) for QueuePool exhaustion
+        # on a 100+ printer SQLite farm, before PostgreSQL was supported. Since
+        # then #2572 made an authenticated request use one checkout instead of
+        # several, which is why 10 + 90 should cover a farm that size. A large
+        # SQLite farm that still exhausts the pool can raise DB_MAX_OVERFLOW,
+        # but is better served by moving to PostgreSQL.
+        pool_size = settings.db_pool_size if settings.db_pool_size is not None else 10
+        max_overflow = settings.db_max_overflow if settings.db_max_overflow is not None else 90
         kwargs = {"pool_size": pool_size, "max_overflow": max_overflow}
     else:
         pool_size = settings.db_pool_size if settings.db_pool_size is not None else 20

+ 89 - 0
backend/app/core/fd_limit.py

@@ -0,0 +1,89 @@
+"""Lift the open-file soft limit to the hard limit at startup (#2883).
+
+Docker, systemd and most native installs start Bambuddy with a soft
+``RLIMIT_NOFILE`` of 1024 and a far higher hard limit. A process may raise its
+own soft limit up to the hard one without privileges, so doing it here reaches
+every install through the code. A ``ulimits`` block in docker-compose.yml would
+not: existing installs keep their own compose file, and on a host whose hard
+limit is lower than the block asks for, the container would not start.
+
+At 1024, running out of descriptors is what turned #2883 into a corrupted
+database: every new SQLite connection failed with "disk I/O error" for 44
+hours. Above 1024 open descriptors the failure is milder. paho-mqtt waits on
+its socket with ``select()``, which cannot take a descriptor numbered 1024 or
+higher; it reports that as a lost connection and reconnects, so printer
+connections drop while the database keeps working.
+"""
+
+import logging
+
+logger = logging.getLogger(__name__)
+
+# What startup found and did, for the support bundle. None until it has run, or
+# on a platform without RLIMIT_NOFILE (Windows).
+startup_status: dict | None = None
+
+# Tried in order when the hard limit is unlimited. macOS reports RLIM_INFINITY
+# but refuses a soft limit above kern.maxfilesperproc, so a finite value has to
+# be picked; 10240 is the usual OPEN_MAX there.
+_UNLIMITED_HARD_TARGETS = (65536, 10240)
+
+
+def _describe(value: int, infinity: int) -> int | str:
+    return "unlimited" if value == infinity else value
+
+
+def raise_open_file_limit() -> dict | None:
+    """Raise the soft open-file limit as far as the hard limit allows.
+
+    Never lowers it, and never raises: a limit that cannot be changed is logged
+    and startup carries on with it. Returns what was found and done, which is
+    also kept in ``startup_status``.
+    """
+    global startup_status
+    try:
+        import resource
+    except ImportError:
+        return None
+
+    infinity = resource.RLIM_INFINITY
+    try:
+        soft, hard = resource.getrlimit(resource.RLIMIT_NOFILE)
+    except (OSError, ValueError) as e:
+        logger.warning("Could not read the open-file limit: %s", e)
+        return None
+
+    status: dict = {
+        "soft_at_start": _describe(soft, infinity),
+        "hard": _describe(hard, infinity),
+        "soft": _describe(soft, infinity),
+        "raised": False,
+    }
+    startup_status = status
+
+    targets = _UNLIMITED_HARD_TARGETS if hard == infinity else (hard,)
+    targets = tuple(t for t in targets if soft != infinity and t > soft)
+    if not targets:
+        logger.info("Open-file limit: %s (hard limit %s)", status["soft"], status["hard"])
+        return status
+
+    error: Exception | None = None
+    for target in targets:
+        try:
+            resource.setrlimit(resource.RLIMIT_NOFILE, (target, hard))
+        except (OSError, ValueError) as e:
+            error = e
+            continue
+        status["soft"] = target
+        status["raised"] = True
+        logger.info("Raised the open-file limit from %s to %s (hard limit %s)", soft, target, status["hard"])
+        return status
+
+    status["error"] = str(error)
+    logger.warning(
+        "Could not raise the open-file limit above %s (hard limit %s): %s",
+        soft,
+        status["hard"],
+        error,
+    )
+    return status

+ 6 - 0
backend/app/main.py

@@ -9594,6 +9594,12 @@ async def lifespan(app: FastAPI):
 
     install_proactor_reset_filter()
 
+    # Before anything opens files or sockets in bulk: a soft limit of 1024 is
+    # what turned descriptor exhaustion into a corrupted database (#2883).
+    from backend.app.core.fd_limit import raise_open_file_limit
+
+    raise_open_file_limit()
+
     # Before init_db, so the warning is near the top of the log rather than
     # below a migration run. See warn_if_running_on_uvloop for what is at stake.
     warn_if_running_on_uvloop()

+ 10 - 3
backend/tests/unit/test_db_pool_and_auth_cache.py

@@ -12,7 +12,14 @@ class TestPoolConfiguration:
     """P0: env-configurable, dialect-aware pool sizing."""
 
     def test_sqlite_defaults_when_unset(self, monkeypatch):
-        """SQLite keeps 20 + 200 when no env override is set."""
+        """SQLite defaults are 10 + 90 when no env override is set (#2883).
+
+        WAL keeps a closed connection's db fd open until the last connection
+        closes, so the pool's fds stay at its peak: ~201 open / ~101 parked
+        here against ~441 / ~221 at the old 20 + 200. That default dates from
+        b8fa2df36, a 100+ printer SQLite farm before #2572 made authenticated
+        requests a single checkout; such a farm can raise DB_MAX_OVERFLOW or
+        move to PostgreSQL."""
         from backend.app.core import database
 
         for attr in ("db_pool_size", "db_max_overflow", "db_pool_timeout", "db_pool_recycle"):
@@ -20,8 +27,8 @@ class TestPoolConfiguration:
         monkeypatch.setattr(database, "is_sqlite", lambda: True)
 
         kwargs = database._resolve_pool_kwargs()
-        assert kwargs["pool_size"] == 20
-        assert kwargs["max_overflow"] == 200
+        assert kwargs["pool_size"] == 10
+        assert kwargs["max_overflow"] == 90
         # No server-socket recycle/pre-ping for a local file.
         assert "pool_pre_ping" not in kwargs
         assert "pool_recycle" not in kwargs

+ 165 - 0
backend/tests/unit/test_fd_limit_2883.py

@@ -0,0 +1,165 @@
+"""The open-file limit is raised at startup, and bundles say what holds it (#2883).
+
+#2883 ran out of descriptors at Docker's default soft limit of 1024. From then
+on every new SQLite connection failed with "disk I/O error", and after 44 hours
+the database was corrupt. The soft limit is the process's own to raise up to the
+hard limit, so startup does that on every install. The support bundle now counts
+descriptors by kind, so the next report shows what held them.
+"""
+
+import resource
+import sqlite3
+from unittest.mock import MagicMock, patch
+
+import pytest
+
+from backend.app.core import fd_limit
+
+INF = resource.RLIM_INFINITY
+
+
+@pytest.fixture(autouse=True)
+def _reset_status():
+    fd_limit.startup_status = None
+    yield
+    fd_limit.startup_status = None
+
+
+def _run(soft, hard, setrlimit=None):
+    calls = []
+
+    def _set(which, limits):
+        calls.append(limits)
+        if setrlimit is not None:
+            setrlimit(limits)
+
+    with (
+        patch.object(resource, "getrlimit", return_value=(soft, hard)),
+        patch.object(resource, "setrlimit", side_effect=_set),
+    ):
+        status = fd_limit.raise_open_file_limit()
+    return status, calls
+
+
+class TestRaiseOpenFileLimit:
+    def test_the_soft_limit_is_raised_to_the_hard_one(self):
+        status, calls = _run(1024, 524288)
+
+        assert calls == [(524288, 524288)]
+        assert status == {"soft_at_start": 1024, "hard": 524288, "soft": 524288, "raised": True}
+        assert fd_limit.startup_status == status
+
+    def test_a_limit_already_at_the_hard_one_is_left_alone(self):
+        status, calls = _run(524288, 524288)
+
+        assert calls == []
+        assert status["raised"] is False
+
+    def test_an_unlimited_soft_limit_is_left_alone(self):
+        status, calls = _run(INF, INF)
+
+        assert calls == []
+        assert status["soft"] == "unlimited"
+
+    def test_an_unlimited_hard_limit_gets_a_finite_soft_one(self):
+        """macOS reports RLIM_INFINITY but refuses a soft limit above
+        kern.maxfilesperproc, so finite values are tried in turn."""
+
+        def refuse_the_first(limits):
+            if limits[0] == 65536:
+                raise ValueError("not allowed")
+
+        status, calls = _run(256, INF, setrlimit=refuse_the_first)
+
+        assert calls == [(65536, INF), (10240, INF)]
+        assert status["soft"] == 10240
+        assert status["hard"] == "unlimited"
+        assert status["raised"] is True
+
+    def test_a_refused_raise_is_logged_and_startup_carries_on(self, caplog):
+        def refuse(limits):
+            raise OSError("operation not permitted")
+
+        status, _ = _run(1024, 4096, setrlimit=refuse)
+
+        assert status["raised"] is False
+        assert status["soft"] == 1024
+        assert "operation not permitted" in status["error"]
+        assert any("Could not raise the open-file limit" in r.getMessage() for r in caplog.records)
+
+    def test_an_unreadable_limit_is_not_fatal(self):
+        with patch.object(resource, "getrlimit", side_effect=OSError("nope")):
+            assert fd_limit.raise_open_file_limit() is None
+
+    def test_no_rlimit_module_is_not_fatal(self):
+        """Windows has no ``resource`` module."""
+        import builtins
+
+        real_import = builtins.__import__
+
+        def no_resource(name, *args, **kwargs):
+            if name == "resource":
+                raise ImportError(name)
+            return real_import(name, *args, **kwargs)
+
+        with patch("builtins.__import__", side_effect=no_resource):
+            assert fd_limit.raise_open_file_limit() is None
+
+
+class TestDescriptorsInTheSupportBundle:
+    @pytest.mark.parametrize(
+        ("target", "kind"),
+        [
+            ("socket:[12345]", "socket"),
+            ("pipe:[678]", "pipe"),
+            ("anon_inode:[eventpoll]", "anon_inode"),
+            ("/app/data/bambuddy.db", "database"),
+            ("/app/data/bambuddy.db-wal", "database_wal"),
+            ("/app/data/bambuddy.db-shm", "database_shm"),
+            ("/dev/null", "device"),
+            ("/app/logs/bambuddy.log", "file"),
+        ],
+    )
+    def test_kinds(self, target, kind):
+        from backend.app.api.routes.support import _fd_kind
+
+        assert _fd_kind(target) == kind
+
+    def test_counts_by_kind_against_the_limit_without_paths(self, tmp_path):
+        import psutil
+
+        from backend.app.api.routes.support import _collect_fd_info
+
+        db = sqlite3.connect(tmp_path / "secret-name.db")
+        db.execute("PRAGMA journal_mode = WAL")
+        db.execute("CREATE TABLE t (x)")
+        try:
+            info = _collect_fd_info(psutil.Process())
+        finally:
+            db.close()
+
+        assert info["num_fds"] > 0
+        assert info["fds_by_type"]["database"] >= 1
+        assert info["fds_by_type"]["database_wal"] >= 1
+        assert set(info["fd_limit"]) == {"soft", "hard"}
+        assert "secret-name" not in repr(info)
+
+    def test_the_startup_result_is_carried(self):
+        from backend.app.api.routes.support import _collect_fd_info
+
+        fd_limit.startup_status = {"soft_at_start": 1024, "hard": 524288, "soft": 524288, "raised": True}
+
+        info = _collect_fd_info(MagicMock())
+
+        assert info["fd_limit_at_startup"]["soft_at_start"] == 1024
+
+    def test_a_failing_probe_still_returns(self):
+        from backend.app.api.routes.support import _collect_fd_info
+
+        proc = MagicMock()
+        proc.num_fds.side_effect = RuntimeError("restricted")
+        with patch("os.listdir", side_effect=PermissionError("no /proc")):
+            info = _collect_fd_info(proc)
+
+        assert "num_fds" not in info
+        assert "fds_by_type" not in info