Recognise rolls put back, use CC2 Control's log for bookings

- A roll put back into the slot it left, with the tag data unchanged, is
  mapped again and CC2 Control's question answered; if the touchscreen then
  replaces the id, it was another roll and goes to storage.
- A touchscreen edit of a scanned roll keeps the mapping and re-answers
  CC2 Control's question so its use is counted.
- Bookings name the print and its result from CC2 Control's log.
- A weigh-in in CC2 Control sets Spoolman's remaining weight instead of
  being booked as use.
- After "Take out" with the roll still in the tray, the tray's logged use
  is booked to that roll until it leaves.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_014GcEk5tkfFSYD6NTF66NkC

tests/fakes.py

@@ -48,6 +48,7 @@ class FakeCC2:
         self.slots[4]["printer"] = None
         self.library: list[dict] = []
         self.job = {"active": False}
+        self.log: list[dict] = []  # newest first, as CC2 Control lists it
         self.calls: list[tuple] = []
         self.fail = False
         self._ids = (f"s{i:04d}" for i in itertools.count(1))
@@ -57,7 +58,7 @@ class FakeCC2:
             raise CC2Error("CC2 Control nicht erreichbar")
 
     def spools_json(self):
-        return {"enabled": self.enabled, "slots": self.slots, "spools": self.library, "job": self.job, "log": []}
+        return {"enabled": self.enabled, "slots": self.slots, "spools": self.library, "job": self.job, "log": self.log}
 
     def spools(self):
         self._check()
@@ -103,6 +104,15 @@ class FakeCC2:
         sp = next(s for s in self.library if s["id"] == cc2_id)
         sp["remaining"] -= grams
 
+    def add_log(self, time, kind="print", spool="", slot=0, grams=0.0, mm=0.0, job="", result=""):
+        self.log.insert(0, {"time": int(time), "spool": spool, "slot": slot, "kind": kind, "grams": grams, "mm": mm,
+                            "job": job, "result": result})
+
+    def weigh(self, cc2_id, remaining, time):
+        sp = next(s for s in self.library if s["id"] == cc2_id)
+        self.add_log(time, "correction", cc2_id, -1, remaining - sp["remaining"], 0, "", "weighed")
+        sp["remaining"] = remaining
+
     def close(self):
         pass
 
@@ -148,7 +158,12 @@ class FakeSpoolman:
         for key, value in (body.get("extra") or {}).items():
             if value is not None and key not in self.field_defs:
                 raise SpoolmanError("Spoolman PATCH: HTTP 400")
-        self.calls.append(("location", sid, body.get("location")))
+        if "location" in body:
+            self.calls.append(("location", sid, body.get("location")))
+        if "used_weight" in body:
+            self.calls.append(("used", sid, body["used_weight"]))
+            sp["used_weight"] = body["used_weight"]
+            sp["remaining_weight"] = sp["initial_weight"] - body["used_weight"]
         if "extra" in body:
             self.calls.append(("extra", sid, dict(body["extra"])))
         if "location" in body:

tests/test_bridge.py

@@ -526,3 +526,236 @@ def test_migration_from_v1(tmp_path):
     assert (tmp_path / "ssh" / "host_key_p1.json").exists()
     assert sm.db[1]["location"] == "Rechts Slot 2" and sm.extra(1) == {"drucker": "Rechts", "slot": 2}
     assert not [c for c in cc2.calls if c[0] in ("save", "assign")]  # nothing re-created
+
+
+# ---------- v3: putting rolls back, CC2 Control's log ----------
+
+def take_out_of_tray(e, slot, pid="p1"):
+    """Roll physically out: tray empty; CC2 Control gives the spool back to storage (record keeps the tag)."""
+    cc2 = e["cc2s"][pid]
+    cc2.slots[slot]["printer"] = {"status": 0}
+    cc2.slots[slot]["spool"] = ""
+    cc2.slots[slot]["question"] = ""
+
+
+def put_back(e, slot, pid="p1"):
+    """Roll in again without a new scan: the record is unchanged, CC2 Control asks."""
+    cc2 = e["cc2s"][pid]
+    cc2.slots[slot]["printer"] = {"status": 1}
+    cc2.slots[slot]["spool"] = ""
+    cc2.slots[slot]["question"] = "inserted"
+
+
+def uses(e):
+    return [c for c in e["sm"].calls if c[0] == "use"]
+
+
+def msgs(e):
+    return [x["msg"] for x in e["bridge"].log.recent()]
+
+
+def test_roll_put_back_after_long_absence_is_mapped_again(env):
+    env["sm"].add(5)
+    insert(env, 1, 5)
+    poll(env)
+    take_out_of_tray(env, 1)
+    poll(env, 6)  # > 20 s
+    assert slots(env) == {} and env["sm"].db[5]["location"] == "Lager"
+    put_back(env, 1)
+    poll(env)
+    assert slots(env)["1"]["spool"] == 5 and slots(env)["1"]["reinserted"]
+    assert env["cc2"].slots[1]["spool"] == "s0001" and env["cc2"].slots[1]["question"] == ""
+    assert env["sm"].db[5]["location"] == "Rechts Slot 2"
+    assert len([c for c in env["cc2"].calls if c[0] == "save"]) == 1  # same mirror
+
+
+def test_put_back_then_touchscreen_edit_means_another_roll(env):
+    env["sm"].add(5)
+    insert(env, 1, 5)
+    poll(env)
+    take_out_of_tray(env, 1)
+    poll(env, 6)
+    put_back(env, 1)  # really an untagged roll ...
+    poll(env)
+    assert slots(env)["1"]["spool"] == 5
+    env["reader"].record["channels1"] = channel(1000)  # ... chosen on the touchscreen
+    env["cc2"].slots[1]["spool"] = ""
+    env["cc2"].slots[1]["question"] = "changed"
+    poll(env, 2)
+    assert slots(env) == {} and env["sm"].db[5]["location"] == "Lager"
+    poll(env, 10)
+    assert slots(env) == {}  # and it does not come back
+
+
+def test_untagged_roll_edited_before_the_bridge_looked(env):
+    env["sm"].add(5)
+    insert(env, 1, 5)
+    poll(env)
+    put_back(env, 1)  # swapped within seconds ...
+    env["reader"].record["channels1"] = channel(1000)  # ... and chosen on the touchscreen
+    poll(env, 2)
+    assert slots(env) == {} and env["sm"].db[5]["location"] == "Lager"
+
+
+def test_short_removal_answers_cc2_again_and_counts(env):
+    env["sm"].add(5, remaining=800)
+    insert(env, 1, 5)
+    poll(env)
+    env["cc2"].slots[1]["printer"] = {"status": 0}
+    poll(env, 2)  # 10 s out, mapping kept
+    put_back(env, 1)
+    poll(env)
+    assert env["cc2"].slots[1]["spool"] == "s0001" and env["cc2"].slots[1]["question"] == ""
+    assert slots(env)["1"]["reinserted"]
+    assert any("erneut zugewiesen" in m for m in msgs(env))
+    env["cc2"].consume("s0001", 2.0)
+    poll(env, 10)
+    assert uses(env) == [("use", 5, 2.0)]
+
+
+def test_touchscreen_edit_of_scanned_roll_keeps_counting(env):
+    env["sm"].add(5)
+    insert(env, 2, 5)
+    poll(env)
+    env["reader"].record["channels2"] = channel(1000)
+    env["cc2"].slots[2]["spool"] = ""
+    env["cc2"].slots[2]["question"] = "changed"
+    poll(env)
+    assert slots(env)["2"]["spool"] == 5
+    assert env["cc2"].slots[2]["spool"] == "s0001"  # question answered with the mapped roll
+    assign_calls = len([c for c in env["cc2"].calls if c[0] == "assign"])
+    env["cc2"].slots[2]["spool"] = ""
+    env["cc2"].slots[2]["question"] = "changed"
+    poll(env, 3, step=5)  # not again within a minute
+    assert len([c for c in env["cc2"].calls if c[0] == "assign"]) == assign_calls
+
+
+def test_take_out_with_roll_still_in_tray_books_from_cc2_log(env):
+    env["sm"].add(5, remaining=800)
+    insert(env, 0, 5)
+    poll(env, 2)
+    env["cc2"].assign(0, None)  # "Take out", roll stays
+    poll(env)
+    assert slots(env) == {} and env["sm"].db[5]["location"] == "Lager"
+    t = env["clock"]()
+    env["cc2"].add_log(t + 30, "print", "", 0, -2.98, 1000.0, "/local/benchy.gcode", "complete")
+    env["cc2"].add_log(t + 30, "print", "", 1, -1.0, 300.0, "/local/benchy.gcode", "complete")  # other tray
+    poll(env, 3)
+    expected = round(1000 * 3.141592653589793 * 0.875 ** 2 * 1.24 / 1000, 3)
+    assert uses(env) == [("use", 5, expected)]
+    assert any("nachgebucht" in m and "benchy.gcode (fertig)" in m for m in msgs(env))
+    e2 = make_env(env["path"], reader=env["reader"], cc2=env["cc2"], spoolman=env["sm"], clock=env["clock"])
+    poll(e2, 3)
+    assert uses(env) == [("use", 5, expected)]
+
+
+def test_take_out_window_closes_when_roll_leaves(env):
+    env["sm"].add(5)
+    insert(env, 0, 5)
+    poll(env, 2)
+    env["cc2"].assign(0, None)
+    poll(env)
+    env["cc2"].slots[0]["printer"] = {"status": 0}
+    poll(env)
+    env["clock"].tick(600)
+    env["cc2"].add_log(env["clock"](), "print", "", 0, -3.0, 1000.0, "x.gcode", "complete")
+    poll(env, 2)
+    assert uses(env) == []
+
+
+def test_old_log_entries_are_not_booked_on_first_start(env):
+    env["sm"].add(5)
+    env["cc2"].add_log(env["clock"]() - 50, "print", "", 0, -3.0, 1000.0, "old.gcode", "complete")
+    insert(env, 0, 5)
+    poll(env, 2)
+    env["cc2"].assign(0, None)
+    poll(env, 3)
+    assert uses(env) == []
+
+
+def test_booking_names_print_and_result(env):
+    env["sm"].add(5, remaining=800)
+    insert(env, 0, 5)
+    poll(env)
+    env["cc2"].job = {"active": True}
+    env["cc2"].consume("s0001", 3.21)
+    poll(env)
+    env["cc2"].job = {"active": False}
+    env["cc2"].add_log(env["clock"](), "print", "s0001", 0, -3.21, 1076.0, "/local/benchy.gcode", "cancelled")
+    poll(env, 10)
+    assert uses(env) == [("use", 5, 3.21)]
+    assert any(m.endswith("gebucht – benchy.gcode (abgebrochen)") for m in msgs(env))
+    assert booked(env)["s0001"]["last"]["details"] == "benchy.gcode (abgebrochen)"
+    env["cc2"].consume("s0001", 1.0)  # next booking does not repeat the old print
+    poll(env, 10)
+    assert msgs(env)[0].endswith("auf Spoolman-Spule 5 gebucht")
+
+
+def test_weigh_in_in_cc2_sets_spoolman_remaining(env):
+    env["sm"].add(5, remaining=800)
+    env["sm"].db[5]["used_weight"] = 200.0
+    insert(env, 0, 5)
+    poll(env)
+    env["cc2"].weigh("s0001", 812.0, env["clock"]())  # more than counted
+    poll(env, 10)
+    assert uses(env) == []
+    assert ("used", 5, 188.0) in env["sm"].calls and env["sm"].db[5]["remaining_weight"] == 812.0
+    env["cc2"].consume("s0001", 2.5)
+    poll(env, 10)
+    assert uses(env) == [("use", 5, 2.5)]
+    assert len([c for c in env["sm"].calls if c[0] == "used"]) == 1
+
+
+def test_weigh_in_lower_is_not_booked_as_use(env):
+    env["sm"].add(5, remaining=800)
+    env["sm"].db[5]["used_weight"] = 200.0
+    insert(env, 0, 5)
+    poll(env)
+    env["cc2"].weigh("s0001", 790.0, env["clock"]())
+    poll(env, 10)
+    assert uses(env) == [] and env["sm"].db[5]["remaining_weight"] == 790.0
+
+
+def test_runout_and_backup_roll(env):
+    env["sm"].add(5, remaining=40)
+    env["sm"].add(8, remaining=1000, color="FFFFFF")
+    insert(env, 0, 5)
+    insert(env, 1, 8, color="0xFFFFFF")
+    poll(env)
+    cc2 = env["cc2"]
+    cc2.job = {"active": True}
+    cc2.consume("s0001", 35.0)  # counted 5 g left when it ran out
+    poll(env)
+    t = env["clock"]()
+    cc2.slots[0]["printer"] = {"status": 0}
+    cc2.slots[0]["spool"] = ""
+    cc2.add_log(t, "print", "s0001", 0, -35.0, 11700.0, "vase.gcode", "runout")
+    cc2.add_log(t, "runout", "s0001", 0, -5.0, 0, "vase.gcode", "runout")
+    cc2.consume("s0001", 5.0)
+    cc2.consume("s0002", 12.0)  # the printer goes on with the other roll
+    poll(env, 6)
+    assert uses(env) == []  # still printing
+    assert "0" not in slots(env) and env["sm"].db[5]["location"] == "Lager"
+    cc2.job = {"active": False}
+    cc2.add_log(env["clock"](), "print", "s0002", 1, -12.0, 4000.0, "vase.gcode", "complete")
+    poll(env, 10)
+    assert sorted(uses(env)) == [("use", 5, 40.0), ("use", 8, 12.0)]
+    assert any("Rolle leergelaufen" in m for m in msgs(env))
+
+
+def test_multicolour_print_books_each_roll(env):
+    for sid in (5, 6, 7):
+        env["sm"].add(sid, remaining=900)
+    insert(env, 0, 5)
+    insert(env, 1, 6)
+    insert(env, 3, 7)
+    poll(env)
+    cc2 = env["cc2"]
+    cc2.job = {"active": True}
+    for _ in range(4):
+        cc2.consume("s0001", 1.5)
+        cc2.consume("s0002", 0.75)
+        poll(env)
+    cc2.job = {"active": False}
+    poll(env, 10)
+    assert sorted(uses(env)) == [("use", 5, 6.0), ("use", 6, 3.0)]