Selaa lähdekoodia

fix(firmware): log an unreachable Bambu Lab site once, not on every firmware check

Without an internet connection, every firmware check of every printer logged
a full ERROR for each Bambu Lab page it fetched, plus a WARNING per model
(measured: 12 ERROR and 9 WARNING lines for three printers checked three
times), all saying the same thing.

FirmwareCheckService now tracks unreachable hosts separately for the wiki and
bambulab.com, since either can fail on its own. The first transport failure
for a host is logged once as a WARNING. Later failures during that outage go
to debug, and the first successful fetch logs "<host> reachable again" at
INFO. The per-model "Could not fetch firmware info" warning also drops to
debug while an outage is known. A wiki fetch that does reach the host but
gets no usable answer, such as a redirect loop or a broken encoding, is
logged at debug and doesn't count as an outage.
maziggy 1 viikko sitten
vanhempi
sitoutus
ae3c27f3df

+ 1 - 0
CHANGELOG.md

@@ -162,6 +162,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
+- **No more firmware-check errors in the log while the internet is down** — Without an internet connection, every firmware check of every printer logged a full error for each Bambu Lab page it tried (measured: 12 errors and 9 warnings for three printers checked three times). The outage is now logged once per Bambu Lab site as a warning, the checks keep retrying quietly, and a line in the log says when the site is reachable again.
 - **Bambu Cloud being unreachable is reported as such** — When Bambu Cloud failed (no internet, a blocked or failing connection, an error or an error page such as a Cloudflare challenge), the cloud preset, device and firmware views answered with a server error (500), and pasting an access token answered as if the token were wrong (401). Signing in or entering the email code without a connection to Bambu Cloud also answered 401, as if the password or code were wrong. These now answer 502 (Bambu Cloud unreachable) with the cause, as the preset lookups already did; a pasted token counts as invalid only when Bambu Cloud itself refuses it. An expired session is answered as such (401, sign in again) instead of with a server error.
 - **Editing a smart plug can no longer save a plug that cannot be read back** — Adding a plug checks its values: a Tasmota plug needs an IPv4 address, a Home Assistant plug an entity of the right kind, an MQTT plug a topic, a REST plug an ON or OFF URL, and the name must not be empty. Editing one did not, so clearing such a field, switching the type without filling in the new one, or typing a hostname as a Tasmota address saved a plug that the smart plug list, the plug itself and the edit all failed on with a server error until it was fixed in the database. Such an edit is now refused with the same message as when adding a plug, and the plug stays as it was. Switching a plug to Tasmota on a printer that already has a Tasmota plug is refused as well (adding one already was); before, it gave the printer a second one, and adding a plug to that printer then failed with a server error.
 - **Importing a project from a file without a priority** — The import gave such a project the priority `0`. On PostgreSQL the import failed with a server error; on SQLite the project got a priority the project editor itself refuses. An imported project now keeps a valid priority (low, normal, high or urgent) and gets **normal** otherwise, from a file and from the JSON import alike.

+ 45 - 6
backend/app/services/firmware_check.py

@@ -13,6 +13,7 @@ import time
 from collections.abc import Callable
 from dataclasses import dataclass
 from pathlib import Path
+from urllib.parse import urlparse
 
 import httpx
 
@@ -158,6 +159,10 @@ class FirmwareCheckService:
                 "Accept-Language": "en-US,en;q=0.9",
             },
         )
+        # Bambu Lab hosts known to be unreachable (no internet, a blocked
+        # host): each outage is logged once, not on every fetch of every check.
+        # Per host, as the wiki and bambulab.com can fail independently.
+        self._unreachable_hosts: set[str] = set()
         # curl_cffi session for bambulab.com (lazily initialised on first use).
         # See module-level note on why this is needed.
         self._bambulab_client: object | None = None
@@ -192,6 +197,27 @@ class FirmwareCheckService:
             )
         return self._bambulab_client
 
+    def _note_unreachable(self, url: str, error: Exception) -> None:
+        """A fetch failed at the transport: log the host's outage once, then quietly."""
+        host = urlparse(url).hostname or url
+        if host in self._unreachable_hosts:
+            logger.debug("%s still unreachable (%s): %s", host, url, error)
+            return
+        self._unreachable_hosts.add(host)
+        logger.warning(
+            "%s unreachable (%s: %s); firmware checks keep retrying, further failures "
+            "are logged at debug level until it is reachable again",
+            host,
+            url,
+            error,
+        )
+
+    def _note_reachable(self, url: str) -> None:
+        host = urlparse(url).hostname or url
+        if host in self._unreachable_hosts:
+            self._unreachable_hosts.discard(host)
+            logger.info("%s reachable again", host)
+
     async def _bambulab_get(self, url: str) -> tuple[int, str]:
         """GET against bambulab.com. Returns (status_code, body_text).
 
@@ -203,16 +229,18 @@ class FirmwareCheckService:
         if client is not None:
             try:
                 response = await client.get(url)  # type: ignore[attr-defined]
-                return response.status_code, response.text
             except Exception as e:
-                logger.error("curl_cffi error fetching %s: %s", url, e)
+                self._note_unreachable(url, e)
                 return 0, ""
+            self._note_reachable(url)
+            return response.status_code, response.text
         try:
             response = await self._client.get(url)
-            return response.status_code, response.text
         except Exception as e:
-            logger.error("httpx error fetching %s: %s", url, e)
+            self._note_unreachable(url, e)
             return 0, ""
+        self._note_reachable(url)
+        return response.status_code, response.text
 
     def _build_id_cache_path(self) -> Path:
         cache_dir = _data_dir / "firmware"
@@ -328,9 +356,18 @@ class FirmwareCheckService:
         if not wiki_path:
             return []
 
+        url = f"{BAMBU_WIKI_BASE}{wiki_path}"
         try:
-            url = f"{BAMBU_WIKI_BASE}{wiki_path}"
             response = await self._client.get(url, follow_redirects=True)
+        except httpx.TransportError as e:
+            self._note_unreachable(url, e)
+            return []
+        except Exception as e:
+            # Reached, but no usable answer (a redirect loop, a broken encoding).
+            logger.debug("Error fetching wiki firmware list for %s: %s", api_key, e)
+            return []
+        self._note_reachable(url)
+        try:
             if response.status_code != 200:
                 return []
 
@@ -454,7 +491,9 @@ class FirmwareCheckService:
         if download_info:
             return download_info
 
-        logger.warning("Could not fetch firmware info for %s from wiki or download page", api_key)
+        # Already reported once as an outage when the sites are unreachable.
+        log = logger.debug if self._unreachable_hosts else logger.warning
+        log("Could not fetch firmware info for %s from wiki or download page", api_key)
         return None
 
     async def get_latest_version(self, model: str) -> FirmwareVersion | None:

+ 123 - 0
backend/tests/unit/services/test_firmware_check_offline_logging.py

@@ -0,0 +1,123 @@
+"""Without internet, the firmware check logs the outage once, not every failure.
+
+Each check of each printer model fetches the Bambu Lab wiki and download page.
+Offline, every one of those fetches logged a full ERROR (and every model a
+WARNING): measured, 3 polls of 3 models gave 12 ERROR and 9 WARNING lines
+saying the same thing. The outage is now logged once as a WARNING, failures
+during it at debug, and the recovery once at INFO.
+"""
+
+from __future__ import annotations
+
+import logging
+from unittest.mock import AsyncMock, MagicMock, patch
+
+import httpx
+import pytest
+
+from backend.app.services.firmware_check import FirmwareCheckService
+
+LOGGER = "backend.app.services.firmware_check"
+
+
+class _Offline:
+    """Both HTTP clients failing at the transport, as without internet."""
+
+    def __init__(self, service: FirmwareCheckService):
+        self.service = service
+        self.online = False
+        self.curl = MagicMock()
+        self.curl.get = AsyncMock(side_effect=self._curl_get)
+
+    async def _curl_get(self, _url):
+        if not self.online:
+            raise RuntimeError("Failed to perform, curl: (7) Couldn't connect to server")
+        return MagicMock(status_code=503, text="")
+
+    async def httpx_get(self, url, **_kwargs):
+        if not self.online:
+            raise httpx.ConnectError("All connection attempts failed")
+        return httpx.Response(200, text='<h2 id="h-01090000-20260101">x</h2>', request=httpx.Request("GET", url))
+
+
+def _records(caplog, level: int) -> list[logging.LogRecord]:
+    return [r for r in caplog.records if r.name == LOGGER and r.levelno == level]
+
+
+@pytest.fixture
+def offline(tmp_path):
+    service = FirmwareCheckService()
+    net = _Offline(service)
+    with (
+        patch("backend.app.services.firmware_check._data_dir", tmp_path),
+        patch.object(service, "_get_bambulab_client", return_value=net.curl),
+        patch.object(service._client, "get", new=net.httpx_get),
+    ):
+        yield service, net
+
+
+@pytest.mark.asyncio
+async def test_an_outage_is_logged_once(offline, caplog):
+    service, _net = offline
+    caplog.set_level(logging.DEBUG, logger=LOGGER)
+
+    for _poll in range(3):
+        for model in ("X1C", "P1S", "H2D"):
+            await service.check_for_update(model, "01.00.00.00")
+
+    assert _records(caplog, logging.ERROR) == []
+    # Once per host: the wiki and bambulab.com fail independently.
+    warnings = [r.getMessage() for r in _records(caplog, logging.WARNING)]
+    assert len(warnings) == 2, warnings
+    assert {w.split()[0] for w in warnings} == {"wiki.bambulab.com", "bambulab.com"}
+    assert all("unreachable" in w for w in warnings)
+
+
+@pytest.mark.asyncio
+async def test_the_recovery_is_logged_and_a_new_outage_warns_again(offline, caplog):
+    service, net = offline
+    caplog.set_level(logging.DEBUG, logger=LOGGER)
+
+    await service.check_for_update("X1C", "01.00.00.00")
+    net.online = True
+    await service.check_for_update("P1S", "01.00.00.00")
+    recovered = [r.getMessage() for r in _records(caplog, logging.INFO) if "reachable again" in r.getMessage()]
+    assert {m.split()[0] for m in recovered} == {"wiki.bambulab.com", "bambulab.com"}
+
+    net.online = False
+    caplog.clear()
+    await service.check_for_update("H2D", "01.00.00.00")
+    assert len(_records(caplog, logging.WARNING)) == 2
+
+
+@pytest.mark.asyncio
+async def test_one_host_down_is_logged_once_without_false_recoveries(offline, caplog):
+    """The wiki answers while bambulab.com does not: one warning for that host,
+    no 'reachable again' from the other."""
+    service, _net = offline
+    caplog.set_level(logging.DEBUG, logger=LOGGER)
+
+    async def wiki_up_only(url, **_kwargs):
+        return httpx.Response(200, text='<h2 id="h-01090000-20260101">x</h2>', request=httpx.Request("GET", url))
+
+    with patch.object(service._client, "get", new=wiki_up_only):
+        for _poll in range(3):
+            for model in ("X1C", "P1S", "H2D"):
+                await service.check_for_update(model, "01.00.00.00")
+
+    assert len(_records(caplog, logging.WARNING)) == 1
+    assert [r for r in _records(caplog, logging.INFO) if "reachable again" in r.getMessage()] == []
+
+
+@pytest.mark.asyncio
+@pytest.mark.parametrize("error", [httpx.TooManyRedirects("loop"), httpx.DecodingError("bad encoding")])
+async def test_a_wiki_error_that_is_not_an_outage_still_degrades_quietly(offline, error):
+    service, _net = offline
+
+    async def failing_wiki(_url, **_kwargs):
+        raise error
+
+    with patch.object(service._client, "get", new=failing_wiki):
+        result = await service.check_for_update("X1C", "01.00.00.00")
+
+    assert isinstance(result, dict)