Judge a hand-back on what a run left, not on the machine still working

A leftover is dirt a run left behind. Four of the checks were reporting
something else: the machine part-way through work of its own, which it
finishes on its own a few seconds later. Each one failed a run that had
done nothing wrong.

laser.arm-wait-lid found it. The test passed every check it makes and
failed on cool=smoke/armed=False/hold=False. The smoke clear is the
engine's post-job work - run duty for smoke_s after an armed session,
timed, ending by itself (cool.c, Cool_Smoke) - and the machine was idle
fifteen seconds later without being asked. Armed and hold were both
false: nothing had been left.

The four, and what each was catching:

  cool         a phase alone (the smoke clear, a cooldown). Armed or
               holding stays a leftover: the run left a job alive and the
               engine is keeping the fans up for it.
  controller   the supervisor's own start. A takeover ends by starting
               forgectrl again, and the respawn runs the liveness probe
               and the lens reference before it reports running and
               verified. The run had put it back.
  state        the ring draining to the end of a job. An underrun stays a
               leftover and is still acknowledged with cnc/stop: that one
               is the run's.
  leds         read_led read brightness, write_led writes target, and the
               smooth trigger fades brightness toward target. An LED the
               machine had already released still read lit mid-fade, and
               the restore called itself done before the fade had moved.
               Judged on target now: a run that left the button lit left
               a target standing.

The waiting, the restoring and the reporting of anything a run actually
left are unchanged. What changed is which readings count as dirt.

Host-proven: 87 baseline unit tests, two of them new - a fading button
LED is not a leftover, a lit one is.

forgetest/forgetest/baseline.py

@@ -182,12 +182,19 @@ def leds_root():
     return r if r.endswith("/") else r + "/"
 
 
-def read_led(name):
+def read_led(name, attr="target"):
-    try:
+    """A button LED's commanded level. The trigger fades brightness toward
-        with open(leds_root() + name + "/brightness") as f:
+    target, so brightness is where the fade has reached and target is what
-            return f.read().strip()
+    the machine was told: a run that left the button lit left a target, and
-    except OSError:
+    a run that ended a moment ago may still be fading from one. Falls back
-        return None
+    to brightness where no target exists."""
+    for a in (attr, "brightness"):
+        try:
+            with open(leds_root() + name + "/" + a) as f:
+                return f.read().strip()
+        except OSError:
+            continue
+    return None
 
 
 def write_led(name, value):
@@ -545,7 +552,14 @@ class Baseline:
             before = (mode.get("controller"), mode.get("motion"))
             mode = self.wait_settled() or mode
             if mode.get("controller") == "running" and mode.get("motion") == "verified":
-                left.append(Leftover("controller", "%s/%s" % before, "running/verified", "waited"))
+                # The supervisor's own work: a takeover ends by starting
+                # forgectrl again, and the respawn runs the liveness probe
+                # and the lens reference before the controller is up and
+                # motion is verified. Waiting for that is right; calling
+                # it a leftover is not, because the run did put it back -
+                # the machine was still doing what it was asked.
+                self.log("controller: %s/%s settled to running/verified on its own; "
+                         "the supervisor's own start, not a leftover" % before)
             else:
                 left.append(Leftover("controller", "%s/%s" % before, "running/verified",
                                      "failed: %s/%s" % (mode.get("controller"), mode.get("motion"))))
@@ -553,14 +567,23 @@ class Baseline:
         st, s = self.fc_get("/status")
         if st == 200 and isinstance(s, dict):
             if s.get("state") != "idle":
-                if s.get("state") == "underrun":
+                # An underrun is the run's: the engine ran out of bytes and
+                # the fault is acknowledged here. Any other state is the
+                # machine finishing what it was given - the ring draining
+                # to the end of a job - and it reaches idle on its own.
+                underrun = s.get("state") == "underrun"
+                if underrun:
                     try:
                         hw.sysfs_write("cnc/stop", "1")     # ack
                     except OSError:
                         pass
                 w = self._wait("idle", lambda: (self.fc_get("/status")[1] or {}).get("state") == "idle", IDLE_S)
-                left.append(Leftover("state", s.get("state"), "idle",
+                if w is not None and not underrun:
-                                     "waited" if w is not None else "failed: not idle"))
+                    self.log("state: %s reached idle on its own after %.0f s; the machine "
+                             "finishing, not a leftover" % (s.get("state"), w))
+                else:
+                    left.append(Leftover("state", s.get("state"), "idle",
+                                         "waited" if w is not None else "failed: not idle"))
             if s.get("laser_locked") is False:
                 try:
                     hw.sysfs_write("cnc/laser_latch", "1")
@@ -575,18 +598,29 @@ class Baseline:
                 found = "%s/armed=%s/hold=%s" % (c.get("phase"), c.get("armed"), c.get("hold"))
                 idle = lambda: (lambda x: x.get("phase") == "idle" and not x.get("armed")     # noqa: E731
                                 and not x.get("hold"))(self.fc_get("/cool/status")[1] or {})
+                # Armed, or holding, is the run's doing. A phase alone is
+                # not: the engine clears smoke at run duty after an armed
+                # session and cools down after a hot one, both timed and
+                # both ending on their own. Waiting for that is right;
+                # calling it a leftover is not, because nothing was left -
+                # the machine was still finishing.
+                dirt = bool(c.get("armed") or c.get("hold"))
                 w = self._wait("cool idle", idle, COOL_IDLE_S)
-                # The engine holds for a job. A run that ended without
+                if w is not None and not dirt:
-                # ending its job leaves one alive, and no amount of
+                    self.log("cool: %s ended on its own after %.0f s; the engine's own post-job "
-                # waiting ends it: stand the machine down and let the
+                             "work, not a leftover" % (found, w))
-                # supervisor bring the controller back clean.
+                else:
-                act = "waited"
+                    # The engine holds for a job. A run that ended without
-                if w is None:
+                    # ending its job leaves one alive, and no amount of
-                    self.stand_down("the cooling engine is still %s" % found)
+                    # waiting ends it: stand the machine down and let the
-                    w = self._wait("cool idle", idle, COOL_IDLE_S)
+                    # supervisor bring the controller back clean.
-                    act = "restored (stood the machine down)"
+                    act = "waited"
-                left.append(Leftover("cool", found, "idle/unarmed/no hold",
+                    if w is None:
-                                     act if w is not None else "failed: still %s" % found))
+                        self.stand_down("the cooling engine is still %s" % found)
+                        w = self._wait("cool idle", idle, COOL_IDLE_S)
+                        act = "restored (stood the machine down)"
+                    left.append(Leftover("cool", found, "idle/unarmed/no hold",
+                                         act if w is not None else "failed: still %s" % found))
 
     def _lamp_side(self, left):
         """The lid lamp at forgectrl's idle level (the lid_lamp_idle setting).
@@ -650,6 +684,9 @@ class Baseline:
                 except OSError as e:
                     act = "failed: %s" % e
                 left.append(Leftover("leds/" + name, got, "0", act))
+            elif (read_led(name, "brightness") or "0") != "0":
+                self.log("leds/%s: target 0, brightness %s; the fade from a level the machine "
+                         "itself ended, not a leftover" % (name, read_led(name, "brightness")))
 
     def _return_head(self, was, now):
         """Jog the head back along its own path by the kernel-measured X/Y

forgetest/tests/test_baseline.py

@@ -52,6 +52,13 @@ class BaselineTests(unittest.TestCase):
         # the class interface writes 'target'; the fake mirrors it into brightness
         # only when the test asks (see _sync_leds)
 
+    def _led2(self, name, target, brightness):
+        """Both attributes of one button LED: the trigger's commanded
+        level and the fade that follows it."""
+        for a, v in (("target", target), ("brightness", brightness)):
+            with open(self.leds + name + "/" + a, "w") as f:
+                f.write(v)
+
     def _sync_leds(self):
         for name in baseline.BUTTON_LEDS:
             p = self.leds + name + "/target"
@@ -370,6 +377,29 @@ if __name__ == "__main__":
     unittest.main()
 
 
+class TransientNotLeftoverTests(BaselineTests):
+    """A leftover is what a run left behind, not the machine part-way
+    through its own work. Found on the bench reference, where
+    laser.arm-wait-lid passed every check it makes and failed its
+    hand-back on the post-job smoke clear."""
+
+    def test_a_fading_button_led_is_not_a_leftover(self):
+        # the trigger fades brightness toward target: target 0 with
+        # brightness still high is the fade from a level the machine ended
+        for name in baseline.BUTTON_LEDS:
+            self._led2(name, target="0", brightness="900")
+        left = self.bl().enforce("post", captured=None)
+        self.assertEqual([x for x in left if x.item.startswith("leds/")], [])
+
+    def test_a_lit_button_led_is_a_leftover(self):
+        # a target the run left standing is dirt, whatever the fade reads
+        self._led2(baseline.BUTTON_LEDS[0], target="1014", brightness="0")
+        left = self.bl().enforce("post", captured=None)
+        items = [x for x in left if x.item.startswith("leds/")]
+        self.assertEqual(len(items), 1)
+        self.assertEqual(items[0].found, "1014")
+
+
 class PositionDeadbandTests(unittest.TestCase):
     """The counters count steps and a controller's own return lands within
     a few hundredths of a millimeter, not on the step: a difference that