Browse Source

Fix greenlet_spawn error in spool auto-assign

  Two lazy-load bugs caused greenlet_spawn errors in the RFID auto-assign
  flow:

  1. create_spool_from_tray set spool.k_profiles=[] AFTER db.flush(),
     but assigning to a relationship on a persistent object triggers a
     lazy load (SQLAlchemy loads the current collection before replacing).
     Moved initialization to BEFORE db.add().

  2. spool.assignments was never initialized or eagerly loaded, so
     db.add(SpoolAssignment) triggered a back_populates lazy load
     outside the async greenlet. Added assignments=[] in create and
     selectinload(Spool.assignments) in get_spool_by_tag.

  Also added exc_info=True to error handlers for full tracebacks, and
  19 new tests including greenlet regression tests that reproduce the
  exact failure.
maziggy 2 months ago
parent
commit
becc4669b1

+ 1 - 1
CHANGELOG.md

@@ -43,7 +43,7 @@ All notable changes to Bambuddy will be documented in this file.
 - **AMS Slot Shows Wrong Material for "Support for" Profiles** — Configuring an AMS slot with a filament profile like "PLA Support for PETG PETG Basic @Bambu Lab H2D 0.4 nozzle" set the slot material to PLA instead of PETG. The name parser iterated material types in order and returned the first match ("PLA"), ignoring that "PLA Support for PETG" means the filament type is PETG. Both the frontend `parsePresetName()` and backend `_parse_material_from_name()` now detect the "X Support for Y" naming pattern and extract the material after "Support for". The frontend also prefers the corrected parsed material over the stored `filament_type` (which may have been saved with the old parser during import).
 - **Firmware Check Shows Wrong Version for H2D Pro** ([#584](https://github.com/maziggy/bambuddy/issues/584)) — H2D Pro printers showed firmware as out of date because the firmware check matched against the H2D firmware track instead of the H2D Pro track. The firmware check's model-to-API-key mapping only had display names (e.g., "H2D", "H2D Pro") but not SSDP device codes (e.g., "O1E", "O2D"). Added all known SSDP model codes to the firmware check mapping so raw device codes resolve to the correct firmware track.
 - **Spurious Error Notifications During Normal Printing (0300_0002)** — Some firmware versions send non-zero `print_error` values in MQTT during normal printing (e.g., `0x03000002` → short code `0300_0002`). The `print_error` parser treated any non-zero value as a real error, appending it to `hms_errors` and triggering notifications — even though the printer was printing fine. All known real HMS error codes have their low 16 bits >= `0x4000` (`0x4xxx` = fatal, `0x8xxx` = warning/pause, `0xCxxx` = prompt). Values below `0x4000` are status/phase indicators, not faults. Now skips values where the error portion is below `0x4000` in both the `print_error` and `hms` array parsers.
-- **K-Profile Apply Fails With Greenlet Error on Auto-Created Spools** — When a Bambu Lab spool was detected via RFID for the first time (auto-creating a new inventory entry), the K-profile application step logged `WARNING greenlet_spawn has not been called; can't call await_only() here`. The `create_spool_from_tray()` function flushed the new spool to the database but didn't eagerly load the `k_profiles` relationship. When `auto_assign_spool()` then iterated `spool.k_profiles` to find a matching K-profile, SQLAlchemy attempted a lazy load — which requires a synchronous DB call that's illegal inside an async context. The K-profile step was silently skipped (caught by `except Exception`), so spool assignment still worked but without K-profile selection. Now eagerly sets `k_profiles = []` on newly created spools since they can never have K-profiles yet.
+- **Spool Auto-Assign Fails With Greenlet Error** ([#612](https://github.com/maziggy/bambuddy/issues/612)) — RFID spool auto-assignment logged `WARNING greenlet_spawn has not been called; can't call await_only() here` and silently failed. The `Spool.assignments` relationship was never eagerly loaded: when `auto_assign_spool()` created a new `SpoolAssignment` and called `db.add()`, SQLAlchemy resolved the FK back-populates synchronously (outside the async greenlet), triggering a lazy load on the uninitialized `spool.assignments` collection. The previous fix only covered `spool.k_profiles`. Now also initializes `spool.assignments = []` on newly created spools in `create_spool_from_tray()`, and adds `selectinload(Spool.assignments)` to both queries in `get_spool_by_tag()` for existing spools. Added `exc_info=True` to the error handlers for full tracebacks in future logs.
 - **SpoolBuddy Link Tag Missing tag_type** — Linking an NFC tag to a spool via the SpoolBuddy dashboard's "Link to Spool" action only set `tag_uid` but left `tag_type` and `data_origin` empty, because it called the generic `updateSpool` API instead of the dedicated `linkTagToSpool` endpoint. The printer card's `LinkSpoolModal` already used `linkTagToSpool` correctly. Now uses `linkTagToSpool` with `tag_type: 'generic'` and `data_origin: 'nfc_link'`, which also handles conflict checks and archived tag recycling.
 - **SpoolBuddy AMS Page Missing Fill Levels for Non-BL Spools** — AMS slots with non-Bambu Lab spools assigned to inventory didn't show fill level bars on the SpoolBuddy AMS page, even though the main printer card displayed them correctly. The SpoolBuddy AMS page only used the MQTT `remain` field (which is -1/unknown for non-BL spools), while the printer card had a fallback chain: Spoolman → inventory → AMS remain. Now fetches inventory spool assignments and computes fill levels from `(label_weight - weight_used) / label_weight`, falling back to AMS remain when no inventory assignment exists.
 - **SpoolBuddy AMS Page Ext-R Slot Falsely Shown as Active When Idle** — On dual-nozzle printers (H2D), the Ext-R slot was incorrectly highlighted as active when the printer was idle. The ext-R tray has `id=255`, and the idle sentinel `tray_now=255` matched it via `trayNow === extTrayId`. The main printer card avoided this by clearing `effectiveTrayNow` to `undefined` when `tray_now=255`. Now guards against `tray_now=255` before any ext slot active check.

+ 2 - 2
backend/app/main.py

@@ -693,7 +693,7 @@ async def on_ams_change(printer_id: int, ams_data: list):
             # Commit any changes (stale deletions and/or fingerprint updates)
             await db.commit()
     except Exception as e:
-        logger.warning("Spool assignment cleanup failed: %s", e)
+        logger.warning("Spool assignment cleanup failed: %s", e, exc_info=True)
 
     # Auto-manage inventory spools from AMS tray data (skip if Spoolman manages AMS)
     try:
@@ -816,7 +816,7 @@ async def on_ams_change(printer_id: int, ams_data: list):
                                 }
                             )
     except Exception as e:
-        logger.warning("RFID spool auto-assign failed: %s", e)
+        logger.warning("RFID spool auto-assign failed: %s", e, exc_info=True)
 
     try:
         async with async_session() as db:

+ 10 - 6
backend/app/services/spool_tag_matcher.py

@@ -142,13 +142,17 @@ async def create_spool_from_tray(db: AsyncSession, tray_data: dict) -> Spool:
         data_origin="rfid_auto",
         tag_type="bambulab",
     )
+    # Initialize relationships BEFORE db.add() to prevent lazy loads.
+    # Setting them after flush() would trigger a lazy load because SQLAlchemy
+    # loads the current collection before replacing it on a persistent object.
+    # They must also be set before add() because cascade processing during
+    # add/flush accesses these collections, and back_populates resolution
+    # when creating SpoolAssignment runs synchronously outside the greenlet.
+    spool.k_profiles = []
+    spool.assignments = []
     db.add(spool)
     await db.flush()
 
-    # Eagerly set k_profiles so callers (auto_assign_spool) don't trigger
-    # a lazy load in async context (greenlet_spawn error).
-    spool.k_profiles = []
-
     logger.info(
         "Auto-created spool %d from AMS tray data: %s %s %s (tag=%s uuid=%s)",
         spool.id,
@@ -170,7 +174,7 @@ async def get_spool_by_tag(db: AsyncSession, tag_uid: str, tray_uuid: str) -> Sp
     if tray_uuid and tray_uuid != ZERO_TRAY_UUID and tray_uuid != "0" * len(tray_uuid):
         result = await db.execute(
             select(Spool)
-            .options(selectinload(Spool.k_profiles))
+            .options(selectinload(Spool.k_profiles), selectinload(Spool.assignments))
             .where(Spool.tray_uuid == tray_uuid, Spool.archived_at.is_(None))
             .limit(1)
         )
@@ -182,7 +186,7 @@ async def get_spool_by_tag(db: AsyncSession, tag_uid: str, tray_uuid: str) -> Sp
     if tag_uid and tag_uid != ZERO_TAG_UID and tag_uid != "0" * len(tag_uid):
         result = await db.execute(
             select(Spool)
-            .options(selectinload(Spool.k_profiles))
+            .options(selectinload(Spool.k_profiles), selectinload(Spool.assignments))
             .where(Spool.tag_uid == tag_uid, Spool.archived_at.is_(None))
             .limit(1)
         )

+ 2 - 0
backend/tests/conftest.py

@@ -70,6 +70,7 @@ async def test_engine():
         ams_label,
         api_key,
         archive,
+        color_catalog,
         external_link,
         filament,
         group,
@@ -84,6 +85,7 @@ async def test_engine():
         smart_plug,
         spool,
         spool_assignment,
+        spool_catalog,
         spool_usage_history,
         user,
     )

+ 354 - 0
backend/tests/unit/services/test_spool_tag_matcher.py

@@ -0,0 +1,354 @@
+"""Tests for spool_tag_matcher service — RFID auto-assign and relationship loading."""
+
+import pytest
+from sqlalchemy import inspect
+
+from backend.app.models.spool import Spool
+from backend.app.models.spool_assignment import SpoolAssignment
+from backend.app.services.spool_tag_matcher import (
+    auto_assign_spool,
+    create_spool_from_tray,
+    get_spool_by_tag,
+    is_bambu_tag,
+    is_valid_tag,
+)
+
+# -- helpers -----------------------------------------------------------------
+
+SAMPLE_TRAY = {
+    "tray_type": "PLA",
+    "tray_sub_brands": "PLA Basic",
+    "tray_color": "FFFFFFFF",
+    "tray_id_name": "",
+    "tag_uid": "AABBCCDD11223344",
+    "tray_uuid": "AABBCCDD11223344AABBCCDD11223344",
+    "tray_info_idx": "GFL99",
+    "nozzle_temp_min": 190,
+    "nozzle_temp_max": 230,
+    "tray_weight": "1000",
+    "remain": 80,
+}
+
+
+def _relationship_is_loaded(obj, attr_name: str) -> bool:
+    """Check if a relationship attribute has been eagerly loaded (not lazy)."""
+    return attr_name in inspect(obj).dict
+
+
+# -- is_valid_tag / is_bambu_tag --------------------------------------------
+
+
+def test_is_valid_tag_with_real_uid():
+    assert is_valid_tag("AABBCCDD11223344", "") is True
+
+
+def test_is_valid_tag_with_real_uuid():
+    assert is_valid_tag("", "AABBCCDD11223344AABBCCDD11223344") is True
+
+
+def test_is_valid_tag_all_zeros():
+    assert is_valid_tag("0000000000000000", "00000000000000000000000000000000") is False
+
+
+def test_is_valid_tag_empty():
+    assert is_valid_tag("", "") is False
+
+
+def test_is_bambu_tag_with_uuid():
+    assert is_bambu_tag("", "AABBCCDD11223344AABBCCDD11223344", "") is True
+
+
+def test_is_bambu_tag_with_uid_and_preset():
+    assert is_bambu_tag("AABBCCDD11223344", "", "GFL99") is True
+
+
+def test_is_bambu_tag_uid_only_no_preset():
+    """A tag UID alone (no UUID, no preset) is NOT considered a Bambu tag."""
+    assert is_bambu_tag("AABBCCDD11223344", "", "") is False
+
+
+# -- create_spool_from_tray -------------------------------------------------
+
+
+@pytest.mark.asyncio
+async def test_create_spool_from_tray_basic(db_session):
+    """Created spool has correct material and tag fields."""
+    spool = await create_spool_from_tray(db_session, SAMPLE_TRAY)
+    await db_session.commit()
+
+    assert spool.id is not None
+    assert spool.material == "PLA"
+    assert spool.brand == "Bambu Lab"
+    assert spool.tag_uid == "AABBCCDD11223344"
+    assert spool.tray_uuid == "AABBCCDD11223344AABBCCDD11223344"
+    assert spool.data_origin == "rfid_auto"
+
+
+@pytest.mark.asyncio
+async def test_create_spool_from_tray_weight_from_remain(db_session):
+    """weight_used is calculated from the AMS remain percentage."""
+    spool = await create_spool_from_tray(db_session, SAMPLE_TRAY)
+    # remain=80 → 20% used → 200g of 1000g
+    assert spool.weight_used == 200.0
+
+
+@pytest.mark.asyncio
+async def test_create_spool_from_tray_relationships_loaded(db_session):
+    """Both k_profiles and assignments must be eagerly initialized.
+
+    If these are lazy, db.add(SpoolAssignment(spool_id=spool.id)) triggers
+    a back_populates lazy load outside the async greenlet → greenlet_spawn error.
+    Regression test for #612.
+    """
+    spool = await create_spool_from_tray(db_session, SAMPLE_TRAY)
+
+    assert _relationship_is_loaded(spool, "k_profiles"), "k_profiles not eagerly initialized"
+    assert _relationship_is_loaded(spool, "assignments"), "assignments not eagerly initialized"
+    assert spool.k_profiles == []
+    assert spool.assignments == []
+
+
+# -- get_spool_by_tag -------------------------------------------------------
+
+
+@pytest.mark.asyncio
+async def test_get_spool_by_tag_by_uuid(db_session):
+    """Look up a spool by tray_uuid."""
+    spool = Spool(
+        material="PLA",
+        tray_uuid="AABBCCDD11223344AABBCCDD11223344",
+        label_weight=1000,
+        core_weight=250,
+    )
+    db_session.add(spool)
+    await db_session.commit()
+
+    found = await get_spool_by_tag(db_session, "", "AABBCCDD11223344AABBCCDD11223344")
+    assert found is not None
+    assert found.id == spool.id
+
+
+@pytest.mark.asyncio
+async def test_get_spool_by_tag_by_uid(db_session):
+    """Fall back to tag_uid when tray_uuid doesn't match."""
+    spool = Spool(
+        material="PETG",
+        tag_uid="1122334455667788",
+        label_weight=1000,
+        core_weight=250,
+    )
+    db_session.add(spool)
+    await db_session.commit()
+
+    found = await get_spool_by_tag(db_session, "1122334455667788", "")
+    assert found is not None
+    assert found.id == spool.id
+
+
+@pytest.mark.asyncio
+async def test_get_spool_by_tag_skips_archived(db_session):
+    """Archived spools are not returned."""
+    from datetime import datetime
+
+    spool = Spool(
+        material="PLA",
+        tray_uuid="AABBCCDD11223344AABBCCDD11223344",
+        label_weight=1000,
+        core_weight=250,
+        archived_at=datetime.now(),
+    )
+    db_session.add(spool)
+    await db_session.commit()
+
+    found = await get_spool_by_tag(db_session, "", "AABBCCDD11223344AABBCCDD11223344")
+    assert found is None
+
+
+@pytest.mark.asyncio
+async def test_get_spool_by_tag_relationships_loaded(db_session):
+    """Both k_profiles and assignments must be eagerly loaded.
+
+    Regression test for #612 — without selectinload(Spool.assignments),
+    accessing spool.assignments after get_spool_by_tag triggers a lazy load
+    in async context → greenlet_spawn error.
+    """
+    spool = Spool(
+        material="PLA",
+        tray_uuid="AABBCCDD11223344AABBCCDD11223344",
+        label_weight=1000,
+        core_weight=250,
+    )
+    db_session.add(spool)
+    await db_session.commit()
+    # Expire to clear in-session state — forces selectinload to actually load
+    db_session.expire(spool)
+
+    found = await get_spool_by_tag(db_session, "", "AABBCCDD11223344AABBCCDD11223344")
+    assert found is not None
+    assert _relationship_is_loaded(found, "k_profiles"), "k_profiles not eagerly loaded"
+    assert _relationship_is_loaded(found, "assignments"), "assignments not eagerly loaded"
+
+
+@pytest.mark.asyncio
+async def test_get_spool_by_tag_returns_none_for_zeros(db_session):
+    """Zero-value tags return None."""
+    found = await get_spool_by_tag(db_session, "0000000000000000", "00000000000000000000000000000000")
+    assert found is None
+
+
+# -- auto_assign_spool (SpoolAssignment creation) ---------------------------
+
+
+@pytest.mark.asyncio
+async def test_auto_assign_creates_assignment(db_session, printer_factory):
+    """auto_assign_spool creates a SpoolAssignment for the given slot."""
+    from unittest.mock import MagicMock
+
+    printer = await printer_factory()
+    spool = await create_spool_from_tray(db_session, SAMPLE_TRAY)
+    await db_session.commit()
+
+    mock_pm = MagicMock()
+    mock_pm.get_status.return_value = None
+    mock_pm.get_client.return_value = None
+
+    assignment = await auto_assign_spool(
+        printer_id=printer.id,
+        ams_id=0,
+        tray_id=2,
+        spool=spool,
+        printer_manager=mock_pm,
+        db=db_session,
+    )
+    await db_session.commit()
+
+    assert assignment.spool_id == spool.id
+    assert assignment.printer_id == printer.id
+    assert assignment.ams_id == 0
+    assert assignment.tray_id == 2
+
+
+@pytest.mark.asyncio
+async def test_auto_assign_replaces_existing(db_session, printer_factory):
+    """auto_assign_spool removes old assignment for the same slot."""
+    from unittest.mock import MagicMock
+
+    from sqlalchemy import select
+
+    printer = await printer_factory()
+
+    # Create two spools
+    spool1 = Spool(material="PLA", label_weight=1000, core_weight=250)
+    spool1.k_profiles = []
+    spool1.assignments = []
+    db_session.add(spool1)
+    await db_session.flush()
+
+    spool2 = Spool(material="PETG", label_weight=1000, core_weight=250)
+    spool2.k_profiles = []
+    spool2.assignments = []
+    db_session.add(spool2)
+    await db_session.flush()
+
+    mock_pm = MagicMock()
+    mock_pm.get_status.return_value = None
+    mock_pm.get_client.return_value = None
+
+    # Assign spool1 to slot
+    await auto_assign_spool(printer.id, 0, 0, spool1, mock_pm, db_session)
+    await db_session.commit()
+
+    # Assign spool2 to same slot — should replace
+    await auto_assign_spool(printer.id, 0, 0, spool2, mock_pm, db_session)
+    await db_session.commit()
+
+    result = await db_session.execute(
+        select(SpoolAssignment).where(
+            SpoolAssignment.printer_id == printer.id,
+            SpoolAssignment.ams_id == 0,
+            SpoolAssignment.tray_id == 0,
+        )
+    )
+    assignments = result.scalars().all()
+    assert len(assignments) == 1
+    assert assignments[0].spool_id == spool2.id
+
+
+@pytest.mark.asyncio
+async def test_auto_assign_no_greenlet_error_new_spool(db_session, printer_factory):
+    """Creating a SpoolAssignment for a newly created spool must not trigger
+    a lazy load on spool.assignments (greenlet_spawn error).
+
+    Regression test for #612: db.add(SpoolAssignment) resolves
+    back_populates synchronously. If spool.assignments is uninitialized,
+    SQLAlchemy attempts a lazy load outside the async greenlet.
+    """
+    from unittest.mock import MagicMock
+
+    printer = await printer_factory()
+    spool = await create_spool_from_tray(db_session, SAMPLE_TRAY)
+    # Don't commit yet — keep spool in same session state as production flow
+
+    mock_pm = MagicMock()
+    mock_pm.get_status.return_value = None
+    mock_pm.get_client.return_value = None
+
+    # This must NOT raise MissingGreenlet / greenlet_spawn error
+    assignment = await auto_assign_spool(
+        printer_id=printer.id,
+        ams_id=0,
+        tray_id=0,
+        spool=spool,
+        printer_manager=mock_pm,
+        db=db_session,
+    )
+    await db_session.commit()
+
+    assert assignment is not None
+    assert assignment.spool_id == spool.id
+
+
+@pytest.mark.asyncio
+async def test_auto_assign_no_greenlet_error_existing_spool(db_session, printer_factory):
+    """Creating a SpoolAssignment for an existing spool (from get_spool_by_tag)
+    must not trigger a lazy load on spool.assignments.
+
+    Regression test for #612.
+    """
+    from unittest.mock import MagicMock
+
+    printer = await printer_factory()
+
+    # Create spool directly (simulating one that was created in a previous session)
+    spool = Spool(
+        material="PLA",
+        tray_uuid="AABBCCDD11223344AABBCCDD11223344",
+        label_weight=1000,
+        core_weight=250,
+    )
+    db_session.add(spool)
+    await db_session.commit()
+    # Expire to clear in-session state — simulates fresh query
+    db_session.expire(spool)
+
+    # Look up via get_spool_by_tag (must eagerly load relationships)
+    found = await get_spool_by_tag(db_session, "", "AABBCCDD11223344AABBCCDD11223344")
+    assert found is not None
+
+    mock_pm = MagicMock()
+    mock_pm.get_status.return_value = None
+    mock_pm.get_client.return_value = None
+
+    # This must NOT raise MissingGreenlet / greenlet_spawn error
+    assignment = await auto_assign_spool(
+        printer_id=printer.id,
+        ams_id=0,
+        tray_id=0,
+        spool=found,
+        printer_manager=mock_pm,
+        db=db_session,
+    )
+    await db_session.commit()
+
+    assert assignment is not None
+    assert assignment.spool_id == found.id