Check the progress a print reports, where a print already runs

Two tests already run a print end to end, and progress is a property of a
running print, so the checks go there rather than into a test of their own
that would cost the operator another job.

cloud.pause-resume takes the job that fits the ring: the client names the
length it is reporting against, and the operator is asked the question only a
person can answer, whether the bar actually moved.

cloud.oversize-stream takes the job that does not fit, which is where a moving
denominator would show: the kernel's program total grows all run long under a
live feed, and the test already samples it growing, so the check is that the
figure progress divides by is larger than that - the job, not the count the
ring had swallowed when the run started.

The forgetest replay plays a captured log from a build that predates the line,
so it carries the line where the current build emits it, as it already does
for the warm-up and the rest.

BRINGUP's cloud item now says a print reports itself again, and what is left
on it is a print watched from the app.

docs/BRINGUP.md

@@ -979,14 +979,16 @@ Open items only. Anything closed is in `CAMPAIGN-LOG.md`.
    than by ring depth (a healthy feeder keeps the ring brim-full, so depth
    only falls an hour after the feed died): thirty seconds of no progress with
    room in the ring stops the job cleanly and retraces, and it resumes if the
-   feed moves again. The remaining gaps are tracked in
+   feed moves again. A running print also reports itself to the app again, on
+   the carrier a factory-session capture settled: the `type:"progress"` frame
+   that is the periodic settings report, every 30 s and at every phase change,
+   divided by the job's own length rather than by the kernel byte counter that
+   climbs all job long under a live feed. The remaining gaps are tracked in
    `python3-gfhardware/forgefirm-app/docs/CLOUD.md` "Outstanding items": a
    live job longer than the ring (built and covered, never yet run from the
    service), the memory guards against a real ceiling rather than a reasoned
-   one, sending progress to the app (F2: the carrier is settled, an outbound
-   `type:"progress"` frame that is the periodic settings report, at 30 s, from
-   a factory-session capture; what is owed is emitting it against the feeder's
-   job total rather than the kernel byte counter), packaged-path boot with
+   one, a print watched from the app to see the bar actually move,
+   packaged-path boot with
    `controller_mode = cloud`, the three unobserved
    actions, the lid-flash LED, and driving the park and the two lifecycle
    periods off the header (`CFrh`, `CCwp`, `CCrp`) once a capture confirms

forgetest/forgetest/suite/cloud.py

@@ -347,6 +347,24 @@ def message(line):
     return line.split(" ", 2)[-1] if line else None
 
 
+PROGRESS_MARK = "print:progress: reporting against "
+
+
+def progress_denominator(lines):
+    """The length the print reported its progress against, or None.
+
+    The client names it once per job, which is the number worth having: it
+    is what every progress frame of that job divides by.
+    """
+    for ln in lines:
+        if PROGRESS_MARK in ln:
+            try:
+                return int(ln.split(PROGRESS_MARK, 1)[1].split()[0])
+            except (IndexError, ValueError):
+                return None
+    return None
+
+
 def session_live(pid):
     """(live, detail): the running cloud client (gfcloud[pid]) has a live
     service session when its last websocket state line is 'ready' - a
@@ -731,7 +749,8 @@ def hunt_lid_open(ctx):
                   "latch stays unlocked and the armed window open through the pause. The same "
                   "print is where the job's lifecycle shows: a print warms up before its first "
                   "fire and rests after its park, both non-zero, while the connect-time hunt in "
-                  "the same session does neither.")
+                  "the same session does neither. It is also where the app's progress bar shows: "
+                  "the run reports how far it has gotten, against the job's own length.")
 def pause_resume(ctx):
     ev = ctx.evidence
     offset = enter_cloud(ctx)
@@ -791,9 +810,20 @@ def pause_resume(ctx):
     ev["holds_before_the_print"] = early_holds
     ctx.check(not early_holds, "a hunt or motion held for a print's periods: %s", early_holds[:2])
 
+    # The app's progress bar, from the same print. The machine reports where
+    # it has gotten to every 30 s and at every phase change, against the
+    # job's own length, which it names once when the run starts.
+    declared = progress_denominator(lines)
+    ev["progress_total"] = declared
+    ctx.log("progress reported against %s bytes", declared)
+    ctx.check(declared is not None, "the print reported no progress at all")
+    ctx.check(declared and declared > 0, "the print reported progress against %s bytes", declared)
+    ctx.confirm("Did the app show the print's progress advancing while it cut, rather than "
+                "standing still or jumping straight to nearly finished?")
+
     settle_cloud(ctx, offset)
-    ctx.log("PASS: button pause/resume mid-print, warm-up and rest observed, job completed "
-            "and parked")
+    ctx.log("PASS: button pause/resume mid-print, warm-up and rest observed, progress reported, "
+            "job completed and parked")
 
 
 @test("cloud.oversize-stream", title="A print longer than the ring is fed while it plays",
@@ -810,8 +840,9 @@ def pause_resume(ctx):
                   "is several times the ring: the machine holds the job in memory, fills the ring, "
                   "starts, and tops the ring up as it drains. This checks the signature of that - "
                   "the device in live-feed mode, the kernel's program total growing during the run, "
-                  "and no underrun - that a live-fed print pauses and resumes the factory way, the "
-                  "ring having kept the history to back into, and that the job still cancels "
+                  "and no underrun - that progress is reported against the job's length rather "
+                  "than that growing total, that a live-fed print pauses and resumes the factory "
+                  "way, the ring having kept the history to back into, and that the job cancels "
                   "cleanly.")
 def oversize_stream(ctx):
     ev = ctx.evidence
@@ -846,6 +877,19 @@ def oversize_stream(ctx):
     ev["underruns_during"] = after
     ctx.check(after == before, "the ring ran dry during the run (underruns %s -> %s)", before, after)
 
+    # Progress on a live feed is where a moving denominator would show. The
+    # kernel's program total is what just grew, and a bar divided by it would
+    # sit near full from the first frame to the last; the job's own length is
+    # what the report divides by, and on a job this long it is the larger
+    # number by a wide margin.
+    declared = progress_denominator(log_lines_since(GFCLOUD_LOG, offset))
+    ev["progress_total"] = declared
+    ctx.log("progress reported against %s bytes, kernel program total %s", declared, grown)
+    ctx.check(declared is not None, "the print reported no progress at all")
+    ctx.check(declared and first is not None and declared > first,
+              "progress is being reported against %s bytes, which is the ring's count (%s), not "
+              "the job", declared, first)
+
     # The pause on a live feed: the ring keeps the history to back into, so a
     # streamed print retraces and leads back on exactly like a preloaded one.
     ev["max_backtrack"] = hw.sysfs_int("cnc/max_backtrack", 0)

forgetest/tests/test_cloud_suite.py

@@ -37,6 +37,8 @@ WARM_UP_LINE = ("2026-08-17T09:44:02.100000+00:00 gfcloud[1522] INFO "
                 "machine:_dwell warm up: holding 3.0 s")
 COOL_DOWN_LINE = ("2026-08-17T09:45:31.700000+00:00 gfcloud[1522] INFO "
                   "machine:_dwell cool down: holding 10.0 s")
+PROGRESS_LINE = ("2026-08-17T09:44:05.200000+00:00 gfcloud[1522] INFO "
+                 "machine:__init__ print:progress: reporting against 47848 bytes every 30 s")
 
 
 def cut(lines, marker, count=1):
@@ -289,9 +291,10 @@ class CloudSuiteTests(unittest.TestCase):
         pre, rest = cut(lines, "waiting for button")
         run_pre, rest = cut(rest, "current state: MachineState.RUNNING")     # the PRINT's run
         # The excerpt was captured before the machine held for a warm-up and
-        # a rest; the replay carries those two lines where it emits them now,
-        # rather than editing what the machine actually said that day.
-        run_pre = run_pre + [WARM_UP_LINE]
+        # a rest, and before it reported a print's progress; the replay
+        # carries those lines where it emits them now, rather than editing
+        # what the machine actually said that day.
+        run_pre = run_pre + [WARM_UP_LINE, PROGRESS_LINE]
         pre, rest = pre + run_pre + [rest[0]], rest[1:]
         mid, tail = cut(rest, at_end)
         tail = tail + [COOL_DOWN_LINE]