Merge pull request #1320 from rommapp/feature/add-offline-support

Added offline support and configurable logging level

backend/config/__init__.py

@@ -108,5 +108,8 @@ def str_to_bool(value: str) -> bool:
 # FRONTEND
 UPLOAD_TIMEOUT = int(os.environ.get("UPLOAD_TIMEOUT", 600))
 
+# LOGGING
+LOGLEVEL: Final = os.environ.get("LOGLEVEL", "INFO")
+
 # TESTING
 IS_PYTEST_RUN: Final = bool(os.environ.get("PYTEST_VERSION", False))

backend/endpoints/sockets/scan.py

@@ -22,11 +22,11 @@
     fs_rom_handler,
 )
 from handler.filesystem.roms_handler import FSRom
-from handler.metadata.igdb_handler import IGDB_API_ENABLED
-from handler.metadata.moby_handler import MOBY_API_ENABLED
 from handler.redis_handler import high_prio_queue, redis_client
 from handler.scan_handler import ScanType, scan_firmware, scan_platform, scan_rom
 from handler.socket_handler import socket_handler
+from logger.formatter import LIGHTYELLOW
+from logger.formatter import highlight as hl
 from logger.logger import log
 from models.platform import Platform
 from models.rom import Rom
@@ -124,11 +124,6 @@ async def scan_platforms(
 
     sm = _get_socket_manager()
 
-    if not IGDB_API_ENABLED and not MOBY_API_ENABLED:
-        log.error("Search error: No metadata providers enabled")
-        await sm.emit("scan:done_ko", "No metadata providers enabled")
-        return
-
     try:
         fs_platforms: list[str] = fs_platform_handler.get_platforms()
     except FolderStructureNotMatchException as e:
@@ -149,11 +144,14 @@ async def stop_scan():
         ] or fs_platforms
 
         if len(platform_list) == 0:
-            log.warn(
-                "⚠️ No platforms found, verify that the folder structure is right and the volume is mounted correctly "
+            log.warning(
+                emoji.emojize(
+                    f"{hl(':warning:', color=LIGHTYELLOW)} No platforms found, verify that the folder structure is right and the volume is mounted correctly. \
+                Check https://github.com/rommapp/romm?tab=readme-ov-file#folder-structure for more details."
+                )
             )
         else:
-            log.info(f"Found {len(platform_list)} platforms in file system ")
+            log.info(f"Found {len(platform_list)} platforms in the file system")
 
         for platform_slug in platform_list:
             scan_stats += await _identify_platform(
@@ -165,11 +163,15 @@ async def stop_scan():
                 socket_manager=sm,
             )
 
-        # Same protection for platforms
+        # Only purge platforms if there are some platforms remaining in the library
+        # This protects against accidental deletion of entries when
+        # the folder structure is not correct or the drive is not mounted
         if len(fs_platforms) > 0:
-            log.info("Purging platforms not found in the filesystem:")
-            log.info("\n".join([f"  - {platform}" for platform in fs_platforms]))
-            db_platform_handler.purge_platforms(fs_platforms)
+            purged_platforms = db_platform_handler.purge_platforms(fs_platforms)
+            if len(purged_platforms) > 0:
+                log.info("Purging platforms not found in the filesystem:")
+                for p in purged_platforms:
+                    log.info(f" - {p.slug}")
 
         log.info(emoji.emojize(":check_mark: Scan completed "))
         await sm.emit("scan:done", scan_stats.__dict__)
@@ -233,7 +235,11 @@ async def _identify_platform(
         fs_firmware = []
 
     if len(fs_firmware) == 0:
-        log.warning("  ⚠️ No firmware found, skipping firmware scan for this platform")
+        log.warning(
+            emoji.emojize(
+                f"  {hl(':warning:', color=LIGHTYELLOW)} No firmware found, skipping firmware scan for this platform"
+            )
+        )
     else:
         log.info(f"  {len(fs_firmware)} firmware files found")
 
@@ -251,9 +257,13 @@ async def _identify_platform(
         return scan_stats
 
     if len(fs_roms) == 0:
-        log.warning("  ⚠️ No roms found, verify that the folder structure is correct")
+        log.warning(
+            emoji.emojize(
+                f"  {hl(':warning:', color=LIGHTYELLOW)} No roms found, verify that the folder structure is correct"
+            )
+        )
     else:
-        log.info(f"  {len(fs_roms)} roms found")
+        log.info(f"  {len(fs_roms)} roms found in the file system")
 
     for fs_rom in fs_roms:
         scan_stats += await _identify_rom(
@@ -268,17 +278,24 @@ async def _identify_platform(
     # Only purge entries if there are some file remaining in the library
     # This protects against accidental deletion of entries when
     # the folder structure is not correct or the drive is not mounted
-
     if len(fs_roms) > 0:
-        log.info("Purging roms not found in the filesystem:")
-        log.info("\n".join([f"  - {rom['file_name']}" for rom in fs_roms]))
-        db_rom_handler.purge_roms(platform.id, [rom["file_name"] for rom in fs_roms])
+        purged_roms = db_rom_handler.purge_roms(
+            platform.id, [rom["file_name"] for rom in fs_roms]
+        )
+        if len(purged_roms) > 0:
+            log.info("Purging roms not found in the filesystem:")
+            for r in purged_roms:
+                log.info(f" - {r.file_name}")
 
     # Same protection for firmware
     if len(fs_firmware) > 0:
-        log.info("Purging firmware not found in the filesystem:")
-        log.info("\n".join([f"  - {fw}" for fw in fs_firmware]))
-        db_firmware_handler.purge_firmware(platform.id, [fw for fw in fs_firmware])
+        purged_firmware = db_firmware_handler.purge_firmware(
+            platform.id, [fw for fw in fs_firmware]
+        )
+        if len(purged_firmware) > 0:
+            log.info("Purging firmware not found in the filesystem:")
+            for f in purged_firmware:
+                log.info(f" - {f}")
 
     return scan_stats
 

backend/handler/database/firmware_handler.py

@@ -62,15 +62,30 @@ def delete_firmware(self, id: int, session: Session = None) -> None:
 
     @begin_session
     def purge_firmware(
-        self, platform_id: int, firmware: list[str], session: Session = None
+        self, platform_id: int, fs_firmwares: list[str], session: Session = None
     ) -> None:
-        return session.execute(
+        purged_firmware = (
+            session.scalars(
+                select(Firmware)
+                .order_by(Firmware.file_name.asc())
+                .where(
+                    and_(
+                        Firmware.platform_id == platform_id,
+                        Firmware.file_name.not_in(fs_firmwares),
+                    )
+                )
+            )  # type: ignore[attr-defined]
+            .unique()
+            .all()
+        )
+        session.execute(
             delete(Firmware)
             .where(
                 and_(
                     Firmware.platform_id == platform_id,
-                    Firmware.file_name.not_in(firmware),
+                    Firmware.file_name.not_in(fs_firmwares),
                 )
             )
             .execution_options(synchronize_session="evaluate")
         )
+        return purged_firmware

backend/handler/database/platforms_handler.py

@@ -59,9 +59,23 @@ def delete_platform(self, id: int, session: Session) -> None:
         )
 
     @begin_session
-    def purge_platforms(self, fs_platforms: list[str], session: Session) -> int:
-        return session.execute(
+    def purge_platforms(
+        self, fs_platforms: list[str], session: Session
+    ) -> Select[tuple[Platform]]:
+        purged_platforms = (
+            session.scalars(
+                select(Platform)
+                .order_by(Platform.name.asc())
+                .where(
+                    or_(Platform.fs_slug.not_in(fs_platforms), Platform.slug.is_(None))
+                )
+            )  # type: ignore[attr-defined]
+            .unique()
+            .all()
+        )
+        session.execute(
             delete(Platform)
             .where(or_(Platform.fs_slug.not_in(fs_platforms), Platform.slug.is_(None)))  # type: ignore[attr-defined]
             .execution_options(synchronize_session="fetch")
         )
+        return purged_platforms

backend/handler/database/roms_handler.py

@@ -191,13 +191,25 @@ def delete_rom(self, id: int, session: Session = None) -> Rom:
 
     @begin_session
     def purge_roms(
-        self, platform_id: int, roms: list[str], session: Session = None
-    ) -> int:
-        return session.execute(
+        self, platform_id: int, fs_roms: list[str], session: Session = None
+    ) -> list[Rom]:
+        purged_roms = (
+            session.scalars(
+                select(Rom)
+                .order_by(Rom.file_name.asc())
+                .where(
+                    and_(Rom.platform_id == platform_id, Rom.file_name.not_in(fs_roms))
+                )
+            )  # type: ignore[attr-defined]
+            .unique()
+            .all()
+        )
+        session.execute(
             delete(Rom)
-            .where(and_(Rom.platform_id == platform_id, Rom.file_name.not_in(roms)))  # type: ignore[attr-defined]
+            .where(and_(Rom.platform_id == platform_id, Rom.file_name.not_in(fs_roms)))  # type: ignore[attr-defined]
             .execution_options(synchronize_session="evaluate")
         )
+        return purged_roms
 
     @begin_session
     def add_rom_user(

backend/handler/metadata/base_hander.py

@@ -191,3 +191,35 @@ async def _mame_format(self, search_term: str) -> str:
             )
 
         return search_term
+
+    def _mask_sensitive_values(self, values: dict[str, str]) -> dict[str, str]:
+        """
+        Mask sensitive values (headers or params), leaving only the first 3 and last 3 characters of the token.
+        This is valid for a dictionary with any of the following keys:
+            - "Authorization" (Bearer token)
+            - "Client-ID"
+            - "Client-Secret"
+            - "client_id"
+            - "client_secret"
+            - "api_key"
+        """
+        return {
+            key: (
+                f"Bearer {values[key].split(' ')[1][:3]}***{values[key].split(' ')[1][-3:]}"
+                if key == "Authorization" and values[key].startswith("Bearer ")
+                else (
+                    f"{values[key][:3]}***{values[key][-3:]}"
+                    if key
+                    in {
+                        "Client-ID",
+                        "Client-Secret",
+                        "client_id",
+                        "client_secret",
+                        "api_key",
+                    }
+                    # Leave other keys unchanged
+                    else values[key]
+                )
+            )
+            for key in values
+        }

backend/handler/metadata/igdb_handler.py

@@ -220,6 +220,14 @@ async def wrapper(*args):
     async def _request(self, url: str, data: str, timeout: int = 120) -> list:
         httpx_client = ctx_httpx_client.get()
         try:
+            masked_headers = self._mask_sensitive_values(self.headers)
+            log.debug(
+                "API request: URL=%s, Headers=%s, Content=%s, Timeout=%s",
+                url,
+                masked_headers,
+                f"{data} limit {self.pagination_limit};",
+                timeout,
+            )
             res = await httpx_client.post(
                 url,
                 content=f"{data} limit {self.pagination_limit};",
@@ -250,6 +258,13 @@ async def _request(self, url: str, data: str, timeout: int = 120) -> list:
             pass
 
         try:
+            log.debug(
+                "Making a second attempt API request: URL=%s, Headers=%s, Content=%s, Timeout=%s",
+                url,
+                masked_headers,
+                f"{data} limit {self.pagination_limit};",
+                timeout,
+            )
             res = await httpx_client.post(
                 url,
                 content=f"{data} limit {self.pagination_limit};",
@@ -606,7 +621,17 @@ async def get_matched_roms_by_name(
         ]
 
 
-class TwitchAuth:
+class TwitchAuth(MetadataHandler):
+    def __init__(self):
+        self.BASE_URL = "https://id.twitch.tv/oauth2/token"
+        self.params = {
+            "client_id": IGDB_CLIENT_ID,
+            "client_secret": IGDB_CLIENT_SECRET,
+            "grant_type": "client_credentials",
+        }
+        self.masked_params = self._mask_sensitive_values(self.params)
+        self.timeout = 10
+
     async def _update_twitch_token(self) -> str:
         token = None
         expires_in = 0
@@ -616,14 +641,16 @@ async def _update_twitch_token(self) -> str:
 
         httpx_client = ctx_httpx_client.get()
         try:
+            log.debug(
+                "API request: URL=%s, Params=%s, Timeout=%s",
+                self.BASE_URL,
+                self.masked_params,
+                self.timeout,
+            )
             res = await httpx_client.post(
-                url="https://id.twitch.tv/oauth2/token",
-                params={
-                    "client_id": IGDB_CLIENT_ID,
-                    "client_secret": IGDB_CLIENT_SECRET,
-                    "grant_type": "client_credentials",
-                },
-                timeout=10,
+                url=self.BASE_URL,
+                params=self.params,
+                timeout=self.timeout,
             )
 
             if res.status_code == 400:

backend/handler/metadata/moby_handler.py

@@ -78,12 +78,23 @@ def extract_metadata_from_moby_rom(rom: dict) -> MobyMetadata:
 
 class MobyGamesHandler(MetadataHandler):
     def __init__(self) -> None:
-        self.platform_url = "https://api.mobygames.com/v1/platforms"
-        self.games_url = "https://api.mobygames.com/v1/games"
+        self.BASE_URL = "https://api.mobygames.com/v1"
+        self.platform_url = f"{self.BASE_URL}/platforms"
+        self.games_url = f"{self.BASE_URL}/games"
 
     async def _request(self, url: str, timeout: int = 120) -> dict:
         httpx_client = ctx_httpx_client.get()
         authorized_url = yarl.URL(url).update_query(api_key=MOBYGAMES_API_KEY)
+        masked_url = authorized_url.with_query(
+            self._mask_sensitive_values(dict(authorized_url.query))
+        )
+
+        log.debug(
+            "API request: URL=%s, Timeout=%s",
+            masked_url,
+            timeout,
+        )
+
         try:
             res = await httpx_client.get(str(authorized_url), timeout=timeout)
             res.raise_for_status()
@@ -107,10 +118,16 @@ async def _request(self, url: str, timeout: int = 120) -> dict:
                 log.error(err)
                 return {}
         except httpx.TimeoutException:
+            log.debug(
+                "Request to URL=%s timed out. Retrying with URL=%s", masked_url, url
+            )
             # Retry the request once if it times out
-            pass
-
         try:
+            log.debug(
+                "API request: URL=%s, Timeout=%s",
+                url,
+                timeout,
+            )
             res = await httpx_client.get(url, timeout=timeout)
             res.raise_for_status()
         except (httpx.HTTPStatusError, httpx.TimeoutException) as err:
@@ -120,7 +137,6 @@ async def _request(self, url: str, timeout: int = 120) -> dict:
             ):
                 # Sometimes Mobygames returns 401 even with a valid API key
                 return {}
-
             # Log the error and return an empty dict if the request fails with a different code
             log.error(err)
             return {}