usage_tracker.py 60 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887888889890891892893894895896897898899900901902903904905906907908909910911912913914915916917918919920921922923924925926927928929930931932933934935936937938939940941942943944945946947948949950951952953954955956957958959960961962963964965966967968969970971972973974975976977978979980981982983984985986987988989990991992993994995996997998999100010011002100310041005100610071008100910101011101210131014101510161017101810191020102110221023102410251026102710281029103010311032103310341035103610371038103910401041104210431044104510461047104810491050105110521053105410551056105710581059106010611062106310641065106610671068106910701071107210731074107510761077107810791080108110821083108410851086108710881089109010911092109310941095109610971098109911001101110211031104110511061107110811091110111111121113111411151116111711181119112011211122112311241125112611271128112911301131113211331134113511361137113811391140114111421143114411451146114711481149115011511152115311541155115611571158115911601161116211631164116511661167116811691170117111721173117411751176117711781179118011811182118311841185118611871188118911901191119211931194119511961197119811991200120112021203120412051206120712081209121012111212121312141215121612171218121912201221122212231224122512261227122812291230123112321233123412351236123712381239124012411242124312441245124612471248124912501251125212531254125512561257125812591260126112621263126412651266126712681269127012711272127312741275127612771278127912801281128212831284128512861287128812891290129112921293129412951296129712981299130013011302130313041305130613071308130913101311131213131314131513161317131813191320132113221323132413251326132713281329133013311332133313341335133613371338133913401341134213431344134513461347134813491350135113521353135413551356135713581359136013611362136313641365136613671368136913701371137213731374137513761377137813791380138113821383138413851386138713881389139013911392139313941395139613971398139914001401140214031404140514061407140814091410141114121413141414151416141714181419142014211422142314241425142614271428142914301431143214331434143514361437143814391440144114421443144414451446144714481449145014511452145314541455
  1. """Automatic filament consumption tracking.
  2. Captures AMS tray remain% at print start, then computes consumption
  3. deltas at print complete to update spool weight_used and last_used.
  4. Primary tracking uses 3MF slicer estimates (precise per-filament data).
  5. AMS remain% delta is the fallback for trays not covered by 3MF data.
  6. """
  7. import json
  8. import logging
  9. from dataclasses import dataclass, field
  10. from datetime import datetime, timezone
  11. from sqlalchemy import select
  12. from sqlalchemy.ext.asyncio import AsyncSession
  13. from backend.app.models.spool import Spool
  14. from backend.app.models.spool_assignment import SpoolAssignment
  15. from backend.app.models.spool_usage_history import SpoolUsageHistory
  16. logger = logging.getLogger(__name__)
  17. def _decode_mqtt_mapping(mapping_raw: list | None) -> list[int] | None:
  18. """Decode MQTT mapping field (snow-encoded) to bambuddy global tray IDs.
  19. The printer's MQTT mapping field is an array indexed by slicer filament slot
  20. (0-based). Each value uses snow encoding: ams_hw_id * 256 + local_slot.
  21. 65535 means unmapped.
  22. Returns a list of bambuddy global tray IDs (or -1 for unmapped), or None if
  23. no valid mappings found.
  24. """
  25. if not isinstance(mapping_raw, list) or not mapping_raw:
  26. return None
  27. result = []
  28. for value in mapping_raw:
  29. if not isinstance(value, int) or value >= 65535:
  30. result.append(-1)
  31. continue
  32. ams_hw_id = value >> 8
  33. slot = value & 0xFF
  34. if 0 <= ams_hw_id <= 3:
  35. # Regular AMS: sequential global ID
  36. result.append(ams_hw_id * 4 + (slot & 0x03))
  37. elif 128 <= ams_hw_id <= 135:
  38. # AMS-HT: global ID is the hardware ID (one slot per unit)
  39. result.append(ams_hw_id)
  40. elif ams_hw_id in (254, 255):
  41. # External spool
  42. result.append(254 if slot != 255 else 255)
  43. else:
  44. result.append(-1)
  45. # Only return if at least one valid mapping exists
  46. if all(v < 0 for v in result):
  47. return None
  48. return result
  49. def _spool_color_to_hex(rgba: str | None) -> str | None:
  50. """Normalise a ``Spool.rgba`` value (``RRGGBBAA`` hex, no ``#``) to the
  51. ``#RRGGBB`` form archives store in ``filament_color``.
  52. Alpha is dropped — the archive colour list and the Color Distribution
  53. graph treat filament colour as opaque. Returns ``None`` for a missing or
  54. too-short value so the caller can fall back to the 3MF colour.
  55. """
  56. if not rgba:
  57. return None
  58. h = rgba.strip().lstrip("#")
  59. if len(h) < 6:
  60. return None
  61. return "#" + h[:6].upper()
  62. def _archive_colors_from_spools(filament_usage: list[dict], results: list[dict]) -> list[str] | None:
  63. """Slot-ordered, de-duplicated hex colours for an archive's ``filament_color``,
  64. taken from the inventory spools that actually fed the print (#1494).
  65. The slicer's 3MF carries its own ``filament_colour`` per slot — a value
  66. picked independently of the colour the user curates on the matched
  67. inventory spool. So an archive printed from a ``#000000`` inventory spool
  68. would otherwise show the slicer's near-black ``#161616``. Once usage
  69. tracking has resolved the used slots to spools, the spool colours are the
  70. authoritative source and replace the 3MF values.
  71. Returns ``None`` — leave the 3MF colour untouched — unless *every* slot
  72. with non-zero usage was matched to a spool that carries a colour. A
  73. partial rewrite would silently drop the unmatched slots' colours from the
  74. archive (and the Color Distribution graph), so it is all-or-nothing.
  75. """
  76. used_slots = {u["slot_id"] for u in filament_usage if u.get("used_g", 0) > 0 and u.get("slot_id") is not None}
  77. if not used_slots:
  78. return None
  79. slot_color: dict[int, str] = {}
  80. for r in results:
  81. slot_id = r.get("slot_id")
  82. color = r.get("color")
  83. if slot_id is not None and color:
  84. slot_color.setdefault(slot_id, color)
  85. if not used_slots.issubset(slot_color):
  86. return None
  87. ordered: list[str] = []
  88. for slot_id in sorted(used_slots):
  89. color = slot_color[slot_id]
  90. if color not in ordered:
  91. ordered.append(color)
  92. return ordered
  93. def _archive_types_from_spools(filament_usage: list[dict], results: list[dict]) -> list[str] | None:
  94. """Slot-ordered, de-duplicated materials for an archive's ``filament_type``,
  95. taken from the inventory spools that actually fed the print (#2563).
  96. The slicer's 3MF records the filament type it was *sliced for*. When the
  97. user manually maps a slot to a differently-typed loaded spool in the Print
  98. dialog — a PLA slice routed to the only loaded PETG slot — that sliced type
  99. misclassifies the run in the archive card, the Print Log and the material
  100. statistics, even though the deduction correctly hit the PETG spool. Once
  101. usage tracking has resolved every used slot to an inventory spool, the
  102. spool's declared material is the authoritative record of what was consumed,
  103. the same reasoning that already adopts the spool colour (#1494).
  104. Returns ``None`` — leave the 3MF type untouched — unless *every* slot with
  105. non-zero usage was matched to a spool that carries a material. All-or-
  106. nothing, exactly like ``_archive_colors_from_spools``: a partial rewrite
  107. would silently drop the unmatched slots' types from the archive (and the
  108. material stats).
  109. """
  110. used_slots = {u["slot_id"] for u in filament_usage if u.get("used_g", 0) > 0 and u.get("slot_id") is not None}
  111. if not used_slots:
  112. return None
  113. slot_material: dict[int, str] = {}
  114. for r in results:
  115. slot_id = r.get("slot_id")
  116. material = (r.get("material") or "").strip()
  117. if slot_id is not None and material:
  118. slot_material.setdefault(slot_id, material)
  119. if not used_slots.issubset(slot_material):
  120. return None
  121. ordered: list[str] = []
  122. for slot_id in sorted(used_slots):
  123. material = slot_material[slot_id]
  124. if material not in ordered:
  125. ordered.append(material)
  126. return ordered
  127. def _match_slots_by_color(
  128. filament_usage: list[dict],
  129. ams_raw: dict | list | None,
  130. ) -> list[int] | None:
  131. """Match 3MF filament slots to AMS trays by color.
  132. Fallback mapping for printers that don't provide the MQTT mapping field
  133. or request topic subscription (e.g. A1, A1 Mini, P1S, P2S).
  134. Compares the 3MF slicer filament color (per slot) against each AMS tray's
  135. color to find a unique match. Only returns a mapping if every used slot
  136. matches exactly one tray (no ambiguity).
  137. Args:
  138. filament_usage: List of 3MF slot dicts with 'slot_id', 'color', 'type'
  139. ams_raw: raw_data["ams"] dict or list from printer state
  140. Returns:
  141. List of global tray IDs indexed by slicer slot (0-based), or None.
  142. """
  143. if not filament_usage or not ams_raw:
  144. return None
  145. ams_data = ams_raw.get("ams", []) if isinstance(ams_raw, dict) else ams_raw if isinstance(ams_raw, list) else []
  146. if not ams_data:
  147. return None
  148. # Build map of normalized color → list of global tray IDs
  149. color_to_trays: dict[str, list[int]] = {}
  150. for ams_unit in ams_data:
  151. ams_id = int(ams_unit.get("id", 0))
  152. for tray in ams_unit.get("tray", []):
  153. tray_id = int(tray.get("id", 0))
  154. tray_color = tray.get("tray_color", "")
  155. tray_type = tray.get("tray_type", "")
  156. if not tray_color or not tray_type:
  157. continue
  158. # Normalize AMS color: strip alpha (last 2 chars), lowercase
  159. norm = tray_color[:6].lower() if len(tray_color) >= 6 else tray_color.lower()
  160. if ams_id >= 128:
  161. global_id = ams_id # AMS-HT
  162. else:
  163. global_id = ams_id * 4 + tray_id
  164. color_to_trays.setdefault(norm, []).append(global_id)
  165. if not color_to_trays:
  166. return None
  167. # Find max slot_id to size the result array
  168. max_slot = max(u.get("slot_id", 0) for u in filament_usage)
  169. if max_slot <= 0:
  170. return None
  171. result = [-1] * max_slot
  172. used_trays: set[int] = set()
  173. for usage in filament_usage:
  174. slot_id = usage.get("slot_id", 0)
  175. if slot_id <= 0:
  176. continue
  177. slot_color = usage.get("color", "").lstrip("#").lower()
  178. if len(slot_color) < 6:
  179. return None # Can't match without a valid color
  180. slot_color = slot_color[:6] # Strip alpha if present
  181. candidates = color_to_trays.get(slot_color, [])
  182. # Filter out trays already claimed by another slot
  183. available = [t for t in candidates if t not in used_trays]
  184. if len(available) != 1:
  185. # Ambiguous (multiple trays with same color) or no match
  186. return None
  187. result[slot_id - 1] = available[0]
  188. used_trays.add(available[0])
  189. # Only return if at least one valid mapping exists
  190. if all(v < 0 for v in result):
  191. return None
  192. logger.info("[UsageTracker] Color-matched slot_to_tray: %s", result)
  193. return result
  194. @dataclass
  195. class PrintSession:
  196. printer_id: int
  197. print_name: str
  198. started_at: datetime
  199. tray_remain_start: dict[tuple[int, int], int] = field(default_factory=dict)
  200. # tray_now at print start (correct value, unlike at completion where it's 255)
  201. tray_now_at_start: int = -1
  202. # Snapshot of spool assignments at print start: {(ams_id, tray_id): spool_id}
  203. # Prevents usage loss when on_ams_change unlinks a spool mid-print
  204. spool_assignments: dict[tuple[int, int], int] = field(default_factory=dict)
  205. # AMS mapping from print command (captured at start, needed when auto-archive is off)
  206. ams_mapping: list[int] | None = None
  207. # Queue item's plate_id when this print is a multi-plate 3MF dispatched for a
  208. # single plate (#1697). None for non-queue prints — the file's first/only plate
  209. # is the default and the 3MF parser already returns the full file in that case.
  210. plate_id: int | None = None
  211. # Module-level storage, keyed by printer_id
  212. _active_sessions: dict[int, PrintSession] = {}
  213. def _to_epoch_seconds(value: datetime | None) -> float | None:
  214. """Convert datetime to epoch seconds, assuming UTC for naive values."""
  215. if value is None:
  216. return None
  217. dt = value
  218. if dt.tzinfo is None:
  219. dt = dt.replace(tzinfo=timezone.utc)
  220. return dt.timestamp()
  221. async def _resolve_spool_id_for_tray(
  222. printer_id: int,
  223. ams_id: int,
  224. tray_id: int,
  225. db: AsyncSession,
  226. spool_assignments_snapshot: dict[tuple[int, int], int] | None = None,
  227. print_started_at: datetime | None = None,
  228. ) -> int | None:
  229. """Resolve spool ID for a tray with safe support for mid-print reassignment.
  230. Resolution order:
  231. 1. If snapshot exists and live assignment changed *during this print*, use live spool.
  232. 2. Otherwise use snapshot spool when available.
  233. 3. Fall back to live assignment.
  234. """
  235. key = (ams_id, tray_id)
  236. snapshot_spool_id = spool_assignments_snapshot.get(key) if spool_assignments_snapshot else None
  237. # Backward-compatible fast path: if we have a snapshot but no print-start
  238. # timestamp, preserve legacy behavior and avoid extra DB lookups.
  239. if snapshot_spool_id is not None and print_started_at is None:
  240. return snapshot_spool_id
  241. result = await db.execute(
  242. select(SpoolAssignment).where(
  243. SpoolAssignment.printer_id == printer_id,
  244. SpoolAssignment.ams_id == ams_id,
  245. SpoolAssignment.tray_id == tray_id,
  246. )
  247. )
  248. live_assignment = result.scalar_one_or_none()
  249. if snapshot_spool_id is not None:
  250. if live_assignment and live_assignment.spool_id != snapshot_spool_id:
  251. live_created_ts = _to_epoch_seconds(getattr(live_assignment, "created_at", None))
  252. started_ts = _to_epoch_seconds(print_started_at)
  253. if live_created_ts is not None and started_ts is not None and live_created_ts >= started_ts:
  254. logger.info(
  255. "[UsageTracker] Assignment changed during print for printer %d AMS%d-T%d: snapshot spool %d -> live spool %d",
  256. printer_id,
  257. ams_id,
  258. tray_id,
  259. snapshot_spool_id,
  260. live_assignment.spool_id,
  261. )
  262. return live_assignment.spool_id
  263. return snapshot_spool_id
  264. if live_assignment:
  265. return live_assignment.spool_id
  266. return None
  267. async def on_print_start(printer_id: int, data: dict, printer_manager, db: AsyncSession | None = None) -> None:
  268. """Capture AMS tray remain% and spool assignments at print start."""
  269. state = printer_manager.get_status(printer_id)
  270. if not state or not state.raw_data:
  271. logger.debug("[UsageTracker] No state for printer %d, skipping", printer_id)
  272. return
  273. ams_raw = state.raw_data.get("ams", [])
  274. ams_data = ams_raw.get("ams", []) if isinstance(ams_raw, dict) else ams_raw if isinstance(ams_raw, list) else []
  275. tray_remain_start: dict[tuple[int, int], int] = {}
  276. skipped_invalid: list[str] = []
  277. for ams_unit in ams_data:
  278. ams_id = int(ams_unit.get("id", 0))
  279. for tray in ams_unit.get("tray", []):
  280. tray_id = int(tray.get("id", 0))
  281. remain = tray.get("remain", -1)
  282. if isinstance(remain, int) and 0 <= remain <= 100:
  283. tray_remain_start[(ams_id, tray_id)] = remain
  284. else:
  285. skipped_invalid.append(f"AMS{ams_id}-T{tray_id}(remain={remain})")
  286. # Also capture VT (external) tray remain% — these are separate from AMS units
  287. vt_tray_raw = state.raw_data.get("vt_tray") or []
  288. if isinstance(vt_tray_raw, dict):
  289. vt_tray_raw = [vt_tray_raw]
  290. for vt in vt_tray_raw:
  291. if not isinstance(vt, dict):
  292. continue
  293. vt_id = int(vt.get("id", 254))
  294. # VT tray id 254 → (ams_id=255, tray_id=0), id 255 → (ams_id=255, tray_id=1)
  295. vt_tray_id = vt_id - 254
  296. remain = vt.get("remain", -1)
  297. if isinstance(remain, int) and 0 <= remain <= 100:
  298. tray_remain_start[(255, vt_tray_id)] = remain
  299. else:
  300. skipped_invalid.append(f"VT{vt_id}(remain={remain})")
  301. if skipped_invalid:
  302. logger.info(
  303. "[UsageTracker] Skipped trays with invalid remain%% for printer %d: %s",
  304. printer_id,
  305. ", ".join(skipped_invalid),
  306. )
  307. if not ams_data and not vt_tray_raw:
  308. logger.debug("[UsageTracker] No AMS or VT tray data for printer %d, skipping", printer_id)
  309. return
  310. print_name = data.get("subtask_name", "") or data.get("filename", "unknown")
  311. # Capture tray_now at print start (reliable, unlike at completion where it's 255)
  312. tray_now_at_start = state.tray_now if state else -1
  313. # --- Diagnostic logging: dump mapping-related MQTT fields at print start ---
  314. # This helps us understand what each printer model reports for slot-to-tray mapping.
  315. mapping_field = state.raw_data.get("mapping")
  316. logger.info(
  317. "[UsageTracker] PRINT START printer %d: mapping=%s, tray_now=%d, last_loaded_tray=%s",
  318. printer_id,
  319. mapping_field,
  320. tray_now_at_start,
  321. getattr(state, "last_loaded_tray", "N/A"),
  322. )
  323. # Log all raw_data keys containing "map" or "ams" for discovery
  324. map_keys = {k: state.raw_data[k] for k in state.raw_data if "map" in k.lower()}
  325. if map_keys:
  326. logger.info("[UsageTracker] PRINT START printer %d: mapping-related keys: %s", printer_id, map_keys)
  327. # Log per-tray summary: tray_now, tray_tar, tray_type, tray_color for each slot
  328. for ams_unit in ams_data:
  329. ams_id = int(ams_unit.get("id", 0))
  330. tray_summary = []
  331. for tray in ams_unit.get("tray", []):
  332. tray_summary.append(
  333. f"T{tray.get('id', '?')}(type={tray.get('tray_type', '')}, "
  334. f"color={tray.get('tray_color', '')}, "
  335. f"now={ams_raw.get('tray_now', '?') if isinstance(ams_raw, dict) else '?'}, "
  336. f"tar={ams_raw.get('tray_tar', '?') if isinstance(ams_raw, dict) else '?'})"
  337. )
  338. logger.info("[UsageTracker] PRINT START printer %d AMS %d: %s", printer_id, ams_id, ", ".join(tray_summary))
  339. # Snapshot spool assignments so usage isn't lost if on_ams_change unlinks mid-print
  340. spool_assignments: dict[tuple[int, int], int] = {}
  341. if db:
  342. assign_result = await db.execute(select(SpoolAssignment).where(SpoolAssignment.printer_id == printer_id))
  343. for assignment in assign_result.scalars().all():
  344. spool_assignments[(assignment.ams_id, assignment.tray_id)] = assignment.spool_id
  345. if spool_assignments:
  346. logger.info(
  347. "[UsageTracker] Snapshotted %d spool assignments for printer %d: %s",
  348. len(spool_assignments),
  349. printer_id,
  350. {f"{k[0]}-{k[1]}": v for k, v in spool_assignments.items()},
  351. )
  352. # Capture the queue item's plate_id so 3MF parsing at completion is scoped to
  353. # the plate that actually ran, not the whole multi-plate file (#1697).
  354. plate_id: int | None = None
  355. if db:
  356. from backend.app.models.print_queue import PrintQueueItem
  357. queue_result = await db.execute(
  358. select(PrintQueueItem)
  359. .where(PrintQueueItem.printer_id == printer_id)
  360. .where(PrintQueueItem.status == "printing")
  361. )
  362. queue_item = queue_result.scalars().first()
  363. if queue_item is not None:
  364. plate_id = queue_item.plate_id
  365. # Always create session (even without valid remain data) so print_name
  366. # is available at completion for 3MF-based tracking
  367. session = PrintSession(
  368. printer_id=printer_id,
  369. print_name=print_name,
  370. started_at=datetime.now(timezone.utc),
  371. tray_remain_start=tray_remain_start,
  372. tray_now_at_start=tray_now_at_start,
  373. spool_assignments=spool_assignments,
  374. ams_mapping=data.get("ams_mapping"),
  375. plate_id=plate_id,
  376. )
  377. _active_sessions[printer_id] = session
  378. if tray_remain_start:
  379. logger.info(
  380. "[UsageTracker] Captured start remain%% for printer %d (%d trays): %s",
  381. printer_id,
  382. len(tray_remain_start),
  383. {f"{k[0]}-{k[1]}": v for k, v in tray_remain_start.items()},
  384. )
  385. else:
  386. logger.debug("[UsageTracker] No valid remain%% for printer %d, 3MF fallback available", printer_id)
  387. async def on_print_complete(
  388. printer_id: int,
  389. data: dict,
  390. printer_manager,
  391. db: AsyncSession,
  392. archive_id: int | None = None,
  393. ams_mapping: list[int] | None = None,
  394. ) -> list[dict]:
  395. """Compute consumption deltas and update spool weight_used/last_used.
  396. Uses two tracking strategies in priority order:
  397. 1. 3MF per-filament estimates (primary) — precise slicer data for all spools
  398. 2. AMS remain% delta (fallback) — only for trays not already handled by 3MF
  399. Returns a list of dicts describing what was logged (for WebSocket broadcast).
  400. """
  401. from sqlalchemy import select
  402. from backend.app.api.routes.settings import get_setting
  403. from backend.app.models.spool_usage_history import SpoolUsageHistory
  404. session = _active_sessions.pop(printer_id, None)
  405. status = data.get("status", "completed")
  406. results = []
  407. handled_trays: set[tuple[int, int]] = set()
  408. # Fetch default filament cost from settings for fallback
  409. default_cost_str = await get_setting(db, "default_filament_cost")
  410. default_filament_cost = float(default_cost_str) if default_cost_str else 0.0
  411. # Fall back to ams_mapping captured at print start (needed when auto-archive is off
  412. # and the caller can't retrieve the mapping from _print_ams_mappings without archive_id)
  413. if not ams_mapping and session and session.ams_mapping:
  414. ams_mapping = session.ams_mapping
  415. logger.info(
  416. "[UsageTracker] on_print_complete: printer=%d, archive=%s, session=%s, ams_mapping=%s",
  417. printer_id,
  418. archive_id,
  419. "yes" if session else "no",
  420. ams_mapping,
  421. )
  422. # --- Diagnostic logging: dump mapping-related MQTT fields at print completion ---
  423. state = printer_manager.get_status(printer_id)
  424. if state and state.raw_data:
  425. logger.info(
  426. "[UsageTracker] PRINT COMPLETE printer %d: mapping=%s, tray_now=%s, last_loaded_tray=%s",
  427. printer_id,
  428. state.raw_data.get("mapping"),
  429. state.tray_now,
  430. getattr(state, "last_loaded_tray", "N/A"),
  431. )
  432. # --- Path 1 (PRIMARY): 3MF per-filament estimates ---
  433. print_name = (
  434. (session.print_name if session else None) or data.get("subtask_name", "") or data.get("filename", "unknown")
  435. )
  436. # When auto-archive is disabled (archive_id=None), try to find a 3MF by filename
  437. # from the library or previous archives so we can still track filament usage.
  438. threemf_path = None
  439. if not archive_id:
  440. from backend.app.core.config import settings as app_settings
  441. search_filename = data.get("filename") or data.get("subtask_name") or (session.print_name if session else "")
  442. if search_filename:
  443. threemf_path = await _find_3mf_by_filename(printer_id, search_filename, db, app_settings.base_dir)
  444. if archive_id or threemf_path:
  445. threemf_results = await _track_from_3mf(
  446. printer_id,
  447. archive_id,
  448. status,
  449. print_name,
  450. handled_trays,
  451. printer_manager,
  452. db,
  453. ams_mapping=ams_mapping,
  454. tray_now_at_start=session.tray_now_at_start if session else -1,
  455. last_progress=data.get("last_progress", 0.0),
  456. last_layer_num=data.get("last_layer_num", 0),
  457. default_filament_cost=default_filament_cost,
  458. spool_assignments=session.spool_assignments if session else None,
  459. print_started_at=session.started_at if session else None,
  460. threemf_path=threemf_path,
  461. plate_id=session.plate_id if session else None,
  462. )
  463. results.extend(threemf_results)
  464. # --- Path 2 (FALLBACK): AMS remain% delta (only for trays not handled by 3MF) ---
  465. if session and session.tray_remain_start:
  466. state = printer_manager.get_status(printer_id)
  467. if state and state.raw_data:
  468. ams_raw = state.raw_data.get("ams", [])
  469. ams_data = (
  470. ams_raw.get("ams", []) if isinstance(ams_raw, dict) else ams_raw if isinstance(ams_raw, list) else []
  471. )
  472. # Build set of trays actually involved in this print (#1269).
  473. # Without this guard, swapping a spool in an UNUSED slot mid-print
  474. # makes that slot's remain% drop to 0, which the fallback below
  475. # would otherwise charge to the originally-assigned spool.
  476. def _global_to_ams_key(global_tray_id: int) -> tuple[int, int]:
  477. if global_tray_id >= 254:
  478. return (255, global_tray_id - 254)
  479. if global_tray_id >= 128:
  480. return (global_tray_id, 0)
  481. return (global_tray_id // 4, global_tray_id % 4)
  482. print_used_keys: set[tuple[int, int]] = set()
  483. if ams_mapping:
  484. for gid in ams_mapping:
  485. if isinstance(gid, int) and gid >= 0:
  486. print_used_keys.add(_global_to_ams_key(gid))
  487. for change in getattr(state, "tray_change_log", None) or []:
  488. if isinstance(change, (tuple, list)) and len(change) >= 1:
  489. gid = change[0]
  490. if isinstance(gid, int) and gid >= 0:
  491. print_used_keys.add(_global_to_ams_key(gid))
  492. if session.tray_now_at_start is not None and session.tray_now_at_start >= 0:
  493. print_used_keys.add(_global_to_ams_key(session.tray_now_at_start))
  494. # Collect all trays to check: AMS trays + VT (external) trays
  495. # Each entry: (ams_id_for_assignment, tray_id_for_assignment, current_remain, label)
  496. trays_to_check: list[tuple[int, int, int, str]] = []
  497. for ams_unit in ams_data:
  498. ams_id = int(ams_unit.get("id", 0))
  499. for tray in ams_unit.get("tray", []):
  500. tray_id = int(tray.get("id", 0))
  501. remain = tray.get("remain", -1)
  502. trays_to_check.append((ams_id, tray_id, remain, f"AMS{ams_id}-T{tray_id}"))
  503. # VT (external) trays — same remain% delta logic
  504. vt_tray_raw = state.raw_data.get("vt_tray") or []
  505. if isinstance(vt_tray_raw, dict):
  506. vt_tray_raw = [vt_tray_raw]
  507. for vt in vt_tray_raw:
  508. if not isinstance(vt, dict):
  509. continue
  510. vt_id = int(vt.get("id", 254))
  511. vt_tray_id = vt_id - 254 # 254→0, 255→1
  512. remain = vt.get("remain", -1)
  513. trays_to_check.append((255, vt_tray_id, remain, f"VT{vt_id}"))
  514. for assign_ams_id, assign_tray_id, current_remain, tray_label in trays_to_check:
  515. key = (assign_ams_id, assign_tray_id)
  516. if key in handled_trays:
  517. continue # Already tracked via 3MF
  518. if key not in session.tray_remain_start:
  519. continue
  520. # Skip trays the print never touched. Only enforce when we have
  521. # evidence of which trays the print used; if print_used_keys is
  522. # empty (no mapping, no change log, no tray_now_at_start) keep
  523. # the legacy behavior of scanning every tray.
  524. if print_used_keys and key not in print_used_keys:
  525. logger.info(
  526. "[UsageTracker] %s: not in print mapping/tray_change_log — skipping fallback for printer %d",
  527. tray_label,
  528. printer_id,
  529. )
  530. continue
  531. if not isinstance(current_remain, int) or current_remain < 0 or current_remain > 100:
  532. logger.info(
  533. "[UsageTracker] %s: invalid remain%% at completion (%s), skipping fallback for printer %d",
  534. tray_label,
  535. current_remain,
  536. printer_id,
  537. )
  538. continue
  539. start_remain = session.tray_remain_start[key]
  540. delta_pct = start_remain - current_remain
  541. if delta_pct <= 0:
  542. continue # No consumption or tray was refilled
  543. spool_id = await _resolve_spool_id_for_tray(
  544. printer_id=printer_id,
  545. ams_id=assign_ams_id,
  546. tray_id=assign_tray_id,
  547. db=db,
  548. spool_assignments_snapshot=session.spool_assignments,
  549. print_started_at=session.started_at,
  550. )
  551. if spool_id is None:
  552. logger.info(
  553. "[UsageTracker] %s: no spool assigned, skipping fallback for printer %d",
  554. tray_label,
  555. printer_id,
  556. )
  557. continue
  558. # Load spool
  559. spool_result = await db.execute(select(Spool).where(Spool.id == spool_id))
  560. spool = spool_result.scalar_one_or_none()
  561. if not spool:
  562. continue
  563. # Compute weight consumed
  564. weight_grams = (delta_pct / 100.0) * spool.label_weight
  565. # Update spool
  566. spool.weight_used = (spool.weight_used or 0) + weight_grams
  567. spool.last_used = datetime.now(timezone.utc)
  568. # Calculate cost for this usage
  569. cost = None
  570. cost_per_kg = spool.cost_per_kg if spool.cost_per_kg is not None else default_filament_cost
  571. if cost_per_kg > 0:
  572. cost = round((weight_grams / 1000.0) * cost_per_kg, 2)
  573. # Insert usage history record
  574. history = SpoolUsageHistory(
  575. spool_id=spool.id,
  576. printer_id=printer_id,
  577. print_name=session.print_name,
  578. weight_used=round(weight_grams, 1),
  579. percent_used=delta_pct,
  580. status=status,
  581. cost=cost,
  582. archive_id=archive_id,
  583. )
  584. db.add(history)
  585. handled_trays.add(key)
  586. results.append(
  587. {
  588. "spool_id": spool.id,
  589. "weight_used": round(weight_grams, 1),
  590. "percent_used": delta_pct,
  591. "ams_id": assign_ams_id,
  592. "tray_id": assign_tray_id,
  593. "material": spool.material,
  594. "cost": cost,
  595. # AMS remain%-delta fallback has no 3MF slot — slot_id
  596. # stays None so it is excluded from the colour rewrite.
  597. "slot_id": None,
  598. "color": _spool_color_to_hex(spool.rgba),
  599. }
  600. )
  601. logger.info(
  602. "[UsageTracker] Spool %d consumed %.1fg (%d%%) on printer %d %s (AMS fallback, %s)",
  603. spool.id,
  604. weight_grams,
  605. delta_pct,
  606. printer_id,
  607. tray_label,
  608. status,
  609. )
  610. if results:
  611. await db.commit()
  612. # --- Update PrintArchive.cost from THIS print session only ---
  613. #
  614. # Cover any filament weight that wasn't tracked by an inventory spool with
  615. # the global default rate (#1344). Without this, a multi-color print where
  616. # only some AMS trays are mapped to inventory spools would record only the
  617. # mapped slots' share — e.g. $0.01 for a 110g print when 3 of 4 trays had
  618. # no spool record. The initial cost set by archive.py (total grams *
  619. # primary cost_per_kg) is fine on its own, but this block overwrites it,
  620. # so the overwrite must reconstruct the whole-print cost.
  621. if archive_id and results:
  622. from sqlalchemy import func, select
  623. from backend.app.models.archive import PrintArchive
  624. from backend.app.models.print_log import PrintLogEntry
  625. archive_result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id))
  626. archive = archive_result.scalar_one_or_none()
  627. if archive:
  628. total_cost = sum(r.get("cost", 0) or 0 for r in results)
  629. tracked_grams = sum(r.get("weight_used", 0) or 0 for r in results)
  630. archive_grams = archive.filament_used_grams or 0
  631. untracked_grams = max(0.0, archive_grams - tracked_grams)
  632. if untracked_grams > 0 and default_filament_cost > 0:
  633. total_cost += (untracked_grams / 1000.0) * default_filament_cost
  634. if total_cost > 0:
  635. # Only overwrite archive.cost on the first run. Reprint actuals
  636. # live in PrintLogEntry; the archive card keeps the first run's
  637. # cost so a failed reprint doesn't visually clobber a successful
  638. # 100 g/$X print with a 10 g/$X/10 partial (#1378).
  639. _existing_runs_result = await db.execute(
  640. select(func.count(PrintLogEntry.id)).where(PrintLogEntry.archive_id == archive_id)
  641. )
  642. _existing_runs = _existing_runs_result.scalar()
  643. if not _existing_runs:
  644. archive.cost = round(total_cost, 2)
  645. await db.commit()
  646. return results
  647. async def _resolve_3mf_fallback(archive, db: AsyncSession, base_dir):
  648. """Try to find a 3MF file from library or a previous archive when the current archive has none.
  649. This handles fallback archives (FTP download failed) where the 3MF may already exist
  650. locally from a library upload or a previous successful print of the same file.
  651. """
  652. from pathlib import Path
  653. from backend.app.models.archive import PrintArchive
  654. from backend.app.models.library import LibraryFile
  655. # Derive search name from archive filename (e.g. "benchy.3mf" or "benchy.gcode.3mf")
  656. search_name = archive.filename or archive.print_name
  657. if not search_name:
  658. return None
  659. # Normalize: strip path parts, get base name
  660. search_name = search_name.split("/")[-1]
  661. search_base = search_name.replace(".gcode.3mf", "").replace(".gcode", "").replace(".3mf", "")
  662. if not search_base:
  663. return None
  664. # 1. Try library files matching the name (match base name at file boundary)
  665. try:
  666. lib_result = await db.execute(
  667. LibraryFile.active()
  668. .where(LibraryFile.file_path.ilike(f"%/{search_base}.%") | LibraryFile.file_path.ilike(f"{search_base}.%"))
  669. .where(LibraryFile.file_path.ilike("%.3mf"))
  670. .order_by(LibraryFile.created_at.desc())
  671. .limit(3)
  672. )
  673. for lib_file in lib_result.scalars().all():
  674. lib_path = Path(lib_file.file_path)
  675. candidate = lib_path if lib_path.is_absolute() else base_dir / lib_file.file_path
  676. if candidate.exists() and candidate.suffix == ".3mf":
  677. logger.info("[UsageTracker] 3MF fallback: found library file %s for archive %s", candidate, archive.id)
  678. return candidate
  679. except Exception as e:
  680. logger.debug("[UsageTracker] 3MF fallback: library lookup failed: %s", e)
  681. # 2. Try previous archives with the same filename that have a valid file_path
  682. try:
  683. prev_result = await db.execute(
  684. select(PrintArchive)
  685. .where(PrintArchive.id != archive.id)
  686. .where(PrintArchive.printer_id == archive.printer_id)
  687. .where(PrintArchive.file_path != "")
  688. .where(PrintArchive.file_path.isnot(None))
  689. .where(
  690. PrintArchive.filename.ilike(f"%{search_base}.%") | PrintArchive.filename.ilike(f"{search_base}.%"),
  691. )
  692. .order_by(PrintArchive.created_at.desc())
  693. .limit(3)
  694. )
  695. for prev_archive in prev_result.scalars().all():
  696. candidate = base_dir / prev_archive.file_path
  697. if candidate.exists() and candidate.suffix == ".3mf":
  698. logger.info(
  699. "[UsageTracker] 3MF fallback: found previous archive %s file for archive %s",
  700. prev_archive.id,
  701. archive.id,
  702. )
  703. return candidate
  704. except Exception as e:
  705. logger.debug("[UsageTracker] 3MF fallback: previous archive lookup failed: %s", e)
  706. return None
  707. async def _find_3mf_by_filename(
  708. printer_id: int,
  709. filename: str,
  710. db: AsyncSession,
  711. base_dir,
  712. ):
  713. """Find a 3MF file by filename from library or previous archives.
  714. Used when auto-archive is disabled and there's no archive_id, but we still
  715. need the 3MF slicer data for filament usage tracking.
  716. """
  717. from pathlib import Path
  718. from backend.app.models.archive import PrintArchive
  719. from backend.app.models.library import LibraryFile
  720. search_name = filename.split("/")[-1] if "/" in filename else filename
  721. search_base = search_name.replace(".gcode.3mf", "").replace(".gcode", "").replace(".3mf", "")
  722. if not search_base:
  723. return None
  724. # 1. Try library files matching the name
  725. try:
  726. lib_result = await db.execute(
  727. LibraryFile.active()
  728. .where(LibraryFile.file_path.ilike(f"%/{search_base}.%") | LibraryFile.file_path.ilike(f"{search_base}.%"))
  729. .where(LibraryFile.file_path.ilike("%.3mf"))
  730. .order_by(LibraryFile.created_at.desc())
  731. .limit(3)
  732. )
  733. for lib_file in lib_result.scalars().all():
  734. lib_path = Path(lib_file.file_path)
  735. candidate = lib_path if lib_path.is_absolute() else base_dir / lib_file.file_path
  736. if candidate.exists() and candidate.suffix == ".3mf":
  737. logger.info("[UsageTracker] 3MF (no-archive): found library file %s for '%s'", candidate, filename)
  738. return candidate
  739. except Exception as e:
  740. logger.debug("[UsageTracker] 3MF (no-archive): library lookup failed: %s", e)
  741. # 2. Try previous archives with a valid 3MF file_path
  742. try:
  743. prev_result = await db.execute(
  744. select(PrintArchive)
  745. .where(PrintArchive.printer_id == printer_id)
  746. .where(PrintArchive.file_path != "")
  747. .where(PrintArchive.file_path.isnot(None))
  748. .where(
  749. PrintArchive.filename.ilike(f"%{search_base}.%") | PrintArchive.filename.ilike(f"{search_base}.%"),
  750. )
  751. .order_by(PrintArchive.created_at.desc())
  752. .limit(3)
  753. )
  754. for prev_archive in prev_result.scalars().all():
  755. candidate = base_dir / prev_archive.file_path
  756. if candidate.exists() and candidate.suffix == ".3mf":
  757. logger.info(
  758. "[UsageTracker] 3MF (no-archive): found previous archive %s file for '%s'",
  759. prev_archive.id,
  760. filename,
  761. )
  762. return candidate
  763. except Exception as e:
  764. logger.debug("[UsageTracker] 3MF (no-archive): previous archive lookup failed: %s", e)
  765. return None
  766. async def _track_from_3mf(
  767. printer_id: int,
  768. archive_id: int | None,
  769. status: str,
  770. print_name: str,
  771. handled_trays: set[tuple[int, int]],
  772. printer_manager,
  773. db: AsyncSession,
  774. ams_mapping: list[int] | None = None,
  775. tray_now_at_start: int = -1,
  776. last_progress: float = 0.0,
  777. last_layer_num: int = 0,
  778. default_filament_cost: float = 0.0,
  779. spool_assignments: dict[tuple[int, int], int] | None = None,
  780. print_started_at: datetime | None = None,
  781. threemf_path=None,
  782. plate_id: int | None = None,
  783. ) -> list[dict]:
  784. """Track usage from 3MF per-filament slicer data (primary path).
  785. Uses slicer-estimated filament weight for all spools (BL and non-BL).
  786. For partial prints (failed/aborted), tries per-layer gcode data first,
  787. then falls back to linear scaling by progress.
  788. When archive_id is None (auto-archive disabled), a pre-resolved threemf_path
  789. can be provided to still track filament usage from slicer data.
  790. When ``plate_id`` is set (queue prints of a single plate from a multi-plate
  791. 3MF), only that plate's filaments contribute. Without it the 3MF parser sums
  792. every plate, which is correct for direct/library Print flows that always
  793. target the first or only plate (#1697).
  794. Slot-to-tray mapping priority:
  795. 1. Stored ams_mapping from print command (reprints/direct prints)
  796. 2. MQTT mapping field from printer state (universal, all print sources)
  797. 3. Queue item ams_mapping (for queue-initiated prints)
  798. 4. tray_now from printer state (for single-filament non-queue prints)
  799. 5. Position-based default using sorted available tray IDs (handles external spools)
  800. 6. Default mapping: slot_id - 1 = global_tray_id (last resort)
  801. """
  802. from pathlib import Path
  803. from backend.app.core.config import settings as app_settings
  804. from backend.app.models.archive import PrintArchive
  805. from backend.app.models.print_queue import PrintQueueItem
  806. from backend.app.utils.threemf_tools import extract_filament_usage_from_3mf
  807. file_path: Path | None = threemf_path
  808. archive: PrintArchive | None = None
  809. if file_path is None and archive_id:
  810. result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id))
  811. archive = result.scalar_one_or_none()
  812. if not archive:
  813. logger.info("[UsageTracker] 3MF: archive %s not found, skipping", archive_id)
  814. return []
  815. # Try archive's own file_path first
  816. if archive.file_path:
  817. candidate = app_settings.base_dir / archive.file_path
  818. if candidate.exists():
  819. file_path = candidate
  820. # Fallback: find 3MF from library or a previous archive with the same filename
  821. if file_path is None:
  822. file_path = await _resolve_3mf_fallback(archive, db, app_settings.base_dir)
  823. if file_path is None:
  824. logger.info("[UsageTracker] 3MF: no file available for archive %s, skipping", archive_id)
  825. return []
  826. filament_usage = extract_filament_usage_from_3mf(file_path, plate_id)
  827. if not filament_usage:
  828. logger.info("[UsageTracker] 3MF: no filament usage data in %s", file_path)
  829. return []
  830. logger.info("[UsageTracker] 3MF: archive %s, plate_id=%s, filament_usage=%s", archive_id, plate_id, filament_usage)
  831. # --- Resolve slot-to-tray mapping ---
  832. mapping_source = None
  833. # 1. Use stored ams_mapping from the print command (reprints/direct prints)
  834. slot_to_tray = ams_mapping
  835. if slot_to_tray:
  836. mapping_source = "print_cmd"
  837. # 2. Try MQTT mapping field from printer state (universal, all print sources)
  838. if not slot_to_tray:
  839. state = printer_manager.get_status(printer_id)
  840. raw_data = getattr(state, "raw_data", None) if state else None
  841. if raw_data:
  842. mqtt_mapping = raw_data.get("mapping")
  843. decoded = _decode_mqtt_mapping(mqtt_mapping)
  844. if decoded:
  845. slot_to_tray = decoded
  846. mapping_source = "mqtt"
  847. # 3. Try queue item ams_mapping (queue-initiated prints store the exact mapping)
  848. if not slot_to_tray and archive_id:
  849. queue_result = await db.execute(
  850. select(PrintQueueItem)
  851. .where(PrintQueueItem.archive_id == archive_id)
  852. .where(PrintQueueItem.status.in_(["printing", "completed", "failed"]))
  853. )
  854. queue_item = queue_result.scalar_one_or_none()
  855. if queue_item and queue_item.ams_mapping:
  856. try:
  857. slot_to_tray = json.loads(queue_item.ams_mapping)
  858. mapping_source = "queue"
  859. except (json.JSONDecodeError, TypeError):
  860. pass
  861. # 4. Color-match 3MF filament slots to AMS trays (for printers without mapping field)
  862. if not slot_to_tray:
  863. state = printer_manager.get_status(printer_id)
  864. raw_data = getattr(state, "raw_data", None) if state else None
  865. if raw_data:
  866. matched = _match_slots_by_color(filament_usage, raw_data.get("ams"))
  867. if matched:
  868. slot_to_tray = matched
  869. mapping_source = "color_match"
  870. logger.info(
  871. "[UsageTracker] 3MF: slot_to_tray=%s (source: %s)",
  872. slot_to_tray,
  873. mapping_source or "none",
  874. )
  875. # 5. For single-filament non-queue prints, use tray_now from printer state
  876. # Priority: tray_change_log (multi-tray split) > tray_now_at_start > current tray_now
  877. # > last_loaded_tray > vt_tray check
  878. #
  879. # tray_change_log evidence wins over slot_to_tray when present: if the
  880. # printer fed from multiple trays mid-print (AMS auto-fallback when one
  881. # spool runs out, #957), the slicer's mapping captured at print start
  882. # is stale and needs to be replaced with per-layer split attribution.
  883. nonzero_slots = [u for u in filament_usage if u.get("used_g", 0) > 0]
  884. tray_now_override: int | None = None
  885. tray_changes: list[tuple[int, int]] = [] # [(global_tray_id, layer_num), ...]
  886. state = printer_manager.get_status(printer_id) if len(nonzero_slots) == 1 else None
  887. if state is not None:
  888. tray_changes = getattr(state, "tray_change_log", []) or []
  889. if len(tray_changes) > 1:
  890. # Multi-tray usage detected — splitting takes over regardless of slot_to_tray.
  891. logger.info("[UsageTracker] 3MF: tray change log: %s (will split weight)", tray_changes)
  892. elif not slot_to_tray and len(nonzero_slots) == 1:
  893. if 0 <= tray_now_at_start <= 254:
  894. tray_now_override = tray_now_at_start
  895. logger.info("[UsageTracker] 3MF: using tray_now_at_start=%d (single-filament fallback)", tray_now_at_start)
  896. elif state and 0 <= state.tray_now <= 254:
  897. tray_now_override = state.tray_now
  898. logger.info("[UsageTracker] 3MF: using current tray_now=%d", state.tray_now)
  899. elif state and 0 <= state.last_loaded_tray <= 253:
  900. tray_now_override = state.last_loaded_tray
  901. logger.info("[UsageTracker] 3MF: using last_loaded_tray=%d (post-retract fallback)", state.last_loaded_tray)
  902. elif state and state.tray_now == 255:
  903. # 255 = "no filament" on legacy printers, but valid 2nd external spool on H2-series
  904. vt_tray = state.raw_data.get("vt_tray") or []
  905. if any(int(vt.get("id", 0)) == 255 for vt in vt_tray if isinstance(vt, dict)):
  906. tray_now_override = state.tray_now
  907. logger.info("[UsageTracker] 3MF: using tray_now=255 (H2-series external spool)")
  908. if tray_now_override is None:
  909. logger.info(
  910. "[UsageTracker] 3MF: no valid tray_now (at_start=%d, current=%s, last_loaded=%s)",
  911. tray_now_at_start,
  912. state.tray_now if state else "N/A",
  913. state.last_loaded_tray if state else "N/A",
  914. )
  915. # Scale factor for partial prints (failed/aborted)
  916. if status == "completed":
  917. scale = 1.0
  918. else:
  919. state = printer_manager.get_status(printer_id)
  920. progress = state.progress if state else 0
  921. # Firmware resets progress to 0 on cancel — use last valid progress captured during print
  922. if progress <= 0 and last_progress > 0:
  923. progress = last_progress
  924. logger.info("[UsageTracker] 3MF: using last_progress=%.1f (firmware reset current to 0)", last_progress)
  925. scale = max(0.0, min(progress / 100.0, 1.0))
  926. # Per-layer gcode accuracy for partial prints
  927. layer_grams: dict[int, float] | None = None
  928. if status != "completed":
  929. state = printer_manager.get_status(printer_id)
  930. current_layer = state.layer_num if state else 0
  931. # Firmware resets layer_num to 0 on cancel — use last valid layer captured during print
  932. if current_layer <= 0 and last_layer_num > 0:
  933. current_layer = last_layer_num
  934. logger.info("[UsageTracker] 3MF: using last_layer_num=%d (firmware reset current to 0)", last_layer_num)
  935. if current_layer > 0:
  936. try:
  937. from backend.app.utils.threemf_tools import (
  938. extract_filament_properties_from_3mf,
  939. extract_layer_filament_usage_from_3mf,
  940. get_cumulative_usage_at_layer,
  941. mm_to_grams,
  942. )
  943. layer_usage = extract_layer_filament_usage_from_3mf(file_path)
  944. if layer_usage:
  945. cumulative_mm = get_cumulative_usage_at_layer(layer_usage, current_layer)
  946. filament_props = extract_filament_properties_from_3mf(file_path)
  947. layer_grams = {}
  948. for filament_id, mm_used in cumulative_mm.items():
  949. slot_id = filament_id + 1 # 0-based to 1-based
  950. props = filament_props.get(slot_id, {})
  951. density = props.get("density", 1.24)
  952. diameter = props.get("diameter", 1.75)
  953. layer_grams[slot_id] = mm_to_grams(mm_used, diameter, density)
  954. except Exception:
  955. pass # Fall back to linear scaling
  956. results = []
  957. for usage in filament_usage:
  958. slot_id = usage.get("slot_id", 0)
  959. used_g = usage.get("used_g", 0)
  960. if used_g <= 0:
  961. continue
  962. # --- Mid-print tray switch: split weight across trays ---
  963. # Split math is shared with the Spoolman writer via
  964. # ``utils.tray_split.compute_tray_split_grams`` (#1793) — both
  965. # inventory backends must attribute segments identically or a
  966. # user running dual-mode sees divergent totals.
  967. if len(tray_changes) > 1:
  968. # Compute total weight for this slot (same logic as normal path)
  969. if layer_grams and slot_id in layer_grams:
  970. total_weight = layer_grams[slot_id]
  971. else:
  972. total_weight = used_g * scale
  973. if total_weight <= 0:
  974. continue
  975. # Extract per-layer gcode for segment splitting
  976. split_layer_usage = None
  977. split_props: dict = {}
  978. try:
  979. from backend.app.utils.threemf_tools import (
  980. extract_filament_properties_from_3mf,
  981. extract_layer_filament_usage_from_3mf,
  982. )
  983. split_layer_usage = extract_layer_filament_usage_from_3mf(file_path)
  984. filament_props = extract_filament_properties_from_3mf(file_path)
  985. split_props = filament_props.get(slot_id, {})
  986. except Exception:
  987. pass # Fall back to linear splitting
  988. from backend.app.utils.tray_split import compute_tray_split_grams
  989. segments = compute_tray_split_grams(
  990. tray_changes=tray_changes,
  991. total_weight=total_weight,
  992. slot_id=slot_id,
  993. layer_usage=split_layer_usage,
  994. density=split_props.get("density", 1.24),
  995. diameter=split_props.get("diameter", 1.75),
  996. total_layers=(state.total_layers if state else 0) or 0,
  997. last_layer_num=last_layer_num,
  998. )
  999. for seg_idx, tray_global, segment_grams in segments:
  1000. if segment_grams <= 0:
  1001. continue
  1002. # Convert global tray ID to (ams_id, tray_id)
  1003. if tray_global >= 254:
  1004. seg_ams_id = 255
  1005. seg_tray_id = tray_global - 254
  1006. elif tray_global >= 128:
  1007. seg_ams_id = tray_global
  1008. seg_tray_id = 0
  1009. else:
  1010. seg_ams_id = tray_global // 4
  1011. seg_tray_id = tray_global % 4
  1012. seg_key = (seg_ams_id, seg_tray_id)
  1013. if seg_key in handled_trays:
  1014. continue
  1015. seg_start_layer = tray_changes[seg_idx][1]
  1016. is_last = seg_idx + 1 >= len(tray_changes)
  1017. logger.info(
  1018. "[UsageTracker] 3MF split: segment %d tray=%d (AMS%d-T%d) layers %d-%s -> %.1fg",
  1019. seg_idx,
  1020. tray_global,
  1021. seg_ams_id,
  1022. seg_tray_id,
  1023. seg_start_layer,
  1024. tray_changes[seg_idx + 1][1] if not is_last else "end",
  1025. segment_grams,
  1026. )
  1027. seg_spool_id = await _resolve_spool_id_for_tray(
  1028. printer_id=printer_id,
  1029. ams_id=seg_ams_id,
  1030. tray_id=seg_tray_id,
  1031. db=db,
  1032. spool_assignments_snapshot=spool_assignments,
  1033. print_started_at=print_started_at,
  1034. )
  1035. if seg_spool_id is None:
  1036. logger.info(
  1037. "[UsageTracker] 3MF split: no spool at printer %d AMS%d-T%d, skipping segment",
  1038. printer_id,
  1039. seg_ams_id,
  1040. seg_tray_id,
  1041. )
  1042. continue
  1043. spool_result = await db.execute(select(Spool).where(Spool.id == seg_spool_id))
  1044. spool = spool_result.scalar_one_or_none()
  1045. if not spool:
  1046. continue
  1047. spool.weight_used = (spool.weight_used or 0) + segment_grams
  1048. spool.last_used = datetime.now(timezone.utc)
  1049. percent = round(segment_grams / (spool.label_weight or 1000) * 100)
  1050. cost = None
  1051. cost_per_kg = spool.cost_per_kg if spool.cost_per_kg is not None else default_filament_cost
  1052. if cost_per_kg > 0:
  1053. cost = round((segment_grams / 1000.0) * cost_per_kg, 2)
  1054. history = SpoolUsageHistory(
  1055. spool_id=spool.id,
  1056. printer_id=printer_id,
  1057. print_name=print_name,
  1058. weight_used=round(segment_grams, 1),
  1059. percent_used=percent,
  1060. status=status,
  1061. cost=cost,
  1062. archive_id=archive_id,
  1063. )
  1064. db.add(history)
  1065. handled_trays.add(seg_key)
  1066. results.append(
  1067. {
  1068. "spool_id": spool.id,
  1069. "weight_used": round(segment_grams, 1),
  1070. "percent_used": percent,
  1071. "ams_id": seg_ams_id,
  1072. "tray_id": seg_tray_id,
  1073. "material": spool.material,
  1074. "cost": cost,
  1075. "slot_id": slot_id,
  1076. "color": _spool_color_to_hex(spool.rgba),
  1077. }
  1078. )
  1079. logger.info(
  1080. "[UsageTracker] Spool %d consumed %.1fg (3MF split seg%d) on printer %d AMS%d-T%d (%s)",
  1081. spool.id,
  1082. segment_grams,
  1083. seg_idx,
  1084. printer_id,
  1085. seg_ams_id,
  1086. seg_tray_id,
  1087. status,
  1088. )
  1089. continue # Skip normal single-tray processing for this slot
  1090. # Map 3MF slot_id to physical (ams_id, tray_id) using resolved mapping
  1091. if tray_now_override is not None:
  1092. # Single-filament non-queue print: use actual tray from printer state
  1093. global_tray_id = tray_now_override
  1094. else:
  1095. # Explicit mapping (print command, MQTT, queue, color match)
  1096. global_tray_id = None
  1097. if slot_to_tray and slot_id <= len(slot_to_tray):
  1098. mapped = slot_to_tray[slot_id - 1]
  1099. if isinstance(mapped, int) and mapped >= 0:
  1100. global_tray_id = mapped
  1101. # Position-based default: sort available tray IDs so external spools (254/255)
  1102. # naturally follow standard AMS trays, matching slicer slot numbering.
  1103. #
  1104. # Filter out AMS slots that have no spool loaded (empty `tray_type`) —
  1105. # BambuStudio/OrcaSlicer compact the slot list when assigning filaments
  1106. # and don't expose empty AMS slots to the user, so the slicer's 3MF
  1107. # slot N maps to the Nth *loaded* tray, not the Nth physical position.
  1108. # Without this filter a "3 AMS slots loaded + 1 empty + external"
  1109. # layout routes the slicer's 4th filament to the empty AMS slot
  1110. # instead of the external (#1607), and the external's spool usage
  1111. # never gets recorded. vt_tray entries are already filtered the
  1112. # same way inside `build_ams_tray_lookup` (line 174 checks
  1113. # `tray_type`), so this just mirrors that for the AMS side.
  1114. if global_tray_id is None:
  1115. _state = printer_manager.get_status(printer_id)
  1116. _raw = getattr(_state, "raw_data", None) if _state else None
  1117. if _raw:
  1118. from backend.app.services.spoolman_tracking import build_ams_tray_lookup
  1119. _lookup = build_ams_tray_lookup(_raw)
  1120. available_trays = sorted(gid for gid, info in _lookup.items() if info.get("tray_type"))
  1121. if slot_id <= len(available_trays):
  1122. global_tray_id = available_trays[slot_id - 1]
  1123. # Final fallback: slot_id - 1 (legacy, works for pure AMS without external spools)
  1124. if global_tray_id is None:
  1125. global_tray_id = slot_id - 1
  1126. if global_tray_id >= 254:
  1127. # External spool: ams_id=255 (sentinel), tray_id=slot index (0 or 1)
  1128. ams_id = 255
  1129. tray_id = global_tray_id - 254
  1130. elif global_tray_id >= 128:
  1131. ams_id = global_tray_id
  1132. tray_id = 0
  1133. else:
  1134. ams_id = global_tray_id // 4
  1135. tray_id = global_tray_id % 4
  1136. logger.info(
  1137. "[UsageTracker] 3MF: slot_id=%d -> global_tray=%d -> AMS%d-T%d (used_g=%.1f, tray_now_override=%s)",
  1138. slot_id,
  1139. global_tray_id,
  1140. ams_id,
  1141. tray_id,
  1142. used_g,
  1143. tray_now_override,
  1144. )
  1145. key = (ams_id, tray_id)
  1146. if key in handled_trays:
  1147. continue
  1148. spool_id = await _resolve_spool_id_for_tray(
  1149. printer_id=printer_id,
  1150. ams_id=ams_id,
  1151. tray_id=tray_id,
  1152. db=db,
  1153. spool_assignments_snapshot=spool_assignments,
  1154. print_started_at=print_started_at,
  1155. )
  1156. if spool_id is None:
  1157. logger.info("[UsageTracker] 3MF: no spool assignment at printer %d AMS%d-T%d", printer_id, ams_id, tray_id)
  1158. continue
  1159. # Load spool
  1160. spool_result = await db.execute(select(Spool).where(Spool.id == spool_id))
  1161. spool = spool_result.scalar_one_or_none()
  1162. if not spool:
  1163. continue
  1164. # Use per-layer grams if available, otherwise linear scale
  1165. if layer_grams and slot_id in layer_grams:
  1166. weight_grams = layer_grams[slot_id]
  1167. else:
  1168. weight_grams = used_g * scale
  1169. if weight_grams <= 0:
  1170. continue
  1171. # Update spool
  1172. spool.weight_used = (spool.weight_used or 0) + weight_grams
  1173. spool.last_used = datetime.now(timezone.utc)
  1174. percent = round(weight_grams / (spool.label_weight or 1000) * 100)
  1175. # Calculate cost for this usage
  1176. cost = None
  1177. cost_per_kg = spool.cost_per_kg if spool.cost_per_kg is not None else default_filament_cost
  1178. if cost_per_kg > 0:
  1179. cost = round((weight_grams / 1000.0) * cost_per_kg, 2)
  1180. # Insert usage history record
  1181. history = SpoolUsageHistory(
  1182. spool_id=spool.id,
  1183. printer_id=printer_id,
  1184. print_name=print_name,
  1185. weight_used=round(weight_grams, 1),
  1186. percent_used=percent,
  1187. status=status,
  1188. cost=cost,
  1189. archive_id=archive_id,
  1190. )
  1191. db.add(history)
  1192. handled_trays.add(key)
  1193. results.append(
  1194. {
  1195. "spool_id": spool.id,
  1196. "weight_used": round(weight_grams, 1),
  1197. "percent_used": percent,
  1198. "ams_id": ams_id,
  1199. "tray_id": tray_id,
  1200. "material": spool.material,
  1201. "cost": cost,
  1202. "slot_id": slot_id,
  1203. "color": _spool_color_to_hex(spool.rgba),
  1204. }
  1205. )
  1206. # Determine mapping source for debug logging
  1207. if tray_now_override is not None:
  1208. map_src = ", tray_now"
  1209. elif mapping_source:
  1210. map_src = f", {mapping_source}_map"
  1211. else:
  1212. map_src = ""
  1213. logger.info(
  1214. "[UsageTracker] Spool %d consumed %.1fg (3MF%s%s) on printer %d AMS%d-T%d (%s)",
  1215. spool.id,
  1216. weight_grams,
  1217. " per-layer" if (layer_grams and slot_id in layer_grams) else (f" scaled {scale:.0%}" if scale < 1 else ""),
  1218. map_src,
  1219. printer_id,
  1220. ams_id,
  1221. tray_id,
  1222. status,
  1223. )
  1224. # --- Adopt the matched inventory spools' colours for the archive (#1494) ---
  1225. # The archive's filament_color was set from the slicer's 3MF at creation
  1226. # time; now that every used slot has been resolved to an inventory spool,
  1227. # the curated spool colour is authoritative. Committed by the caller's
  1228. # `if results: await db.commit()`.
  1229. if archive is not None:
  1230. spool_colors = _archive_colors_from_spools(filament_usage, results)
  1231. if spool_colors:
  1232. joined = ",".join(spool_colors)
  1233. if joined != archive.filament_color:
  1234. logger.info(
  1235. "[UsageTracker] 3MF: archive %s filament_color %r -> %r (from inventory spools)",
  1236. archive_id,
  1237. archive.filament_color,
  1238. joined,
  1239. )
  1240. archive.filament_color = joined
  1241. # Adopt the matched spools' materials too (#2563) — a slot mapped to a
  1242. # differently-typed spool than it was sliced for otherwise records the
  1243. # sliced type in the archive, Print Log and material stats.
  1244. spool_types = _archive_types_from_spools(filament_usage, results)
  1245. if spool_types:
  1246. joined_types = ",".join(spool_types)
  1247. if joined_types != archive.filament_type:
  1248. logger.info(
  1249. "[UsageTracker] 3MF: archive %s filament_type %r -> %r (from inventory spools)",
  1250. archive_id,
  1251. archive.filament_type,
  1252. joined_types,
  1253. )
  1254. archive.filament_type = joined_types
  1255. return results