Measure each fix from the move to fixing to delivered, and say one over its budget (issue 403)

hq ADR 0313: the operator's five minutes start when an agent moves the issue
to fixing, not at the merge. mesh-delivery says on each transition, and in
checks, when the pull request opened, when it merged and the class of what it
moves. mesh-issues keeps the first move to fixing, the fix time with its four
phases once the last fix is delivered, serves fix-times, and says
issue-tracker.fix.<class>.over-budget on the operator's channel, cleared by the
next fix of that class within budget.

modules/mesh-issues/cmd/mesh-issues/delivery.go

@@ -37,6 +37,34 @@ type Fix struct {
 	Since       time.Time  `json:"since"`
 	// StuckSaid says it was said stuck, on the issue and to the operator's channel.
 	StuckSaid bool `json:"stuck-said,omitempty"`
+	// Class is the class of what its delivery moves, as mesh-delivery says it: core, leaf, or none when it moves
+	// no module; Opened when its pull request was first heard (novox/hq ADR 0313 §2, §4).
+	Class  string     `json:"class,omitempty"`
+	Opened *time.Time `json:"opened,omitempty"`
+}
+
+// heardFix is what the delivery said of a pull request at one moment: its state, why, whether it is merged, and
+// what a fix's time is read by — the class of what it moves, when its pull request opened and when it merged,
+// each when said.
+type heardFix struct {
+	State    string
+	Why      string
+	Merged   bool
+	At       time.Time
+	Class    string
+	Opened   *time.Time
+	MergedAt *time.Time
+}
+
+// news says whether what was heard adds anything to what a fix keeps.
+func (h heardFix) news(f *Fix, kept string) bool {
+	if f.State != h.State || f.Why != kept || (h.Merged && !f.Merged) || (h.Class != "" && h.Class != f.Class) {
+		return true
+	}
+	if h.Opened != nil && (f.Opened == nil || !f.Opened.Equal(*h.Opened)) {
+		return true
+	}
+	return h.MergedAt != nil && (f.MergedAt == nil || !f.MergedAt.Equal(*h.MergedAt))
 }
 
 // reached says whether a delivery's state says the change reached the machines (mesh-delivery's Reached).
@@ -147,7 +175,8 @@ func DeliveryLine(is *Issue) string {
 
 // recordFix keeps what the delivery said of a pull request on every issue whose fixed-by names it (only, when
 // given, on that one issue), and answers the issues it changed.
-func (t *Tracker) recordFix(pr, state, why string, merged bool, at time.Time, only uint64) ([]uint64, error) {
+func (t *Tracker) recordFix(pr string, h heardFix, only uint64) ([]uint64, error) {
+	state, why, merged, at := h.State, h.Why, h.Merged, h.At
 	all, err := t.allIssues()
 	if err != nil {
 		return nil, err
@@ -158,7 +187,7 @@ func (t *Tracker) recordFix(pr, state, why string, merged bool, at time.Time, on
 			continue
 		}
 		kept := cut(why, MostReasonKept)
-		if f := fixOf(is, pr); f != nil && (at.Before(f.Since) || (f.State == state && f.Why == kept && f.Merged == (merged || f.Merged))) {
+		if f := fixOf(is, pr); f != nil && (at.Before(f.Since) || !h.news(f, kept)) {
 			// Older than what is kept, or nothing new: transitions can arrive out of order.
 			continue
 		}
@@ -179,6 +208,17 @@ func (t *Tracker) recordFix(pr, state, why string, merged bool, at time.Time, on
 				m := at
 				f.MergedAt = &m
 			}
+			if h.MergedAt != nil && (merged || f.Merged) {
+				m := h.MergedAt.UTC()
+				f.MergedAt = &m // the delivery's own moment of the merge, not when it was heard
+			}
+			if h.Class != "" {
+				f.Class = h.Class
+			}
+			if h.Opened != nil {
+				o := h.Opened.UTC()
+				f.Opened = &o
+			}
 			if reached(state) && !contains(i.Delivered, pr) {
 				i.Delivered = append(i.Delivered, pr)
 			}
@@ -207,6 +247,10 @@ func (t *Tracker) afterFix(n uint64) error {
 		t.Logf("[mesh-issues] the warning that %d is delivered and not resolved could not be cleared on the operator's channel (tried again at the next sweep): %v", n, err)
 	}
 	if allDelivered(is) {
+		// Its fix time, final once its last fix is delivered (novox/hq ADR 0313).
+		if err := t.timeFix(n); err != nil {
+			return err
+		}
 		if unresolved(is) {
 			prs := liveFixes(is)
 			sort.Strings(prs)
@@ -321,12 +365,15 @@ func prKey(repository string, number int) string {
 // to is kept on each issue whose fixed-by names it.
 func (t *Tracker) OnTransition(e stdio.Envelope) error {
 	var body struct {
-		Repository string    `json:"repository"`
-		Number     int       `json:"number"`
-		To         string    `json:"to"`
-		Why        string    `json:"why"`
-		MergedAs   string    `json:"merged_as"`
-		At         time.Time `json:"at"`
+		Repository string     `json:"repository"`
+		Number     int        `json:"number"`
+		To         string     `json:"to"`
+		Why        string     `json:"why"`
+		MergedAs   string     `json:"merged_as"`
+		At         time.Time  `json:"at"`
+		Class      string     `json:"class"`
+		Opened     *time.Time `json:"opened"`
+		MergedAt   *time.Time `json:"merged_at"`
 	}
 	if err := json.Unmarshal(e.Body, &body); err != nil || body.To == "" || body.Number <= 0 {
 		return nil
@@ -336,7 +383,8 @@ func (t *Tracker) OnTransition(e stdio.Envelope) error {
 		at = t.now()
 	}
 	merged := body.MergedAs != ""
-	changed, err := t.recordFix(prKey(body.Repository, body.Number), body.To, body.Why, merged, at, 0)
+	changed, err := t.recordFix(prKey(body.Repository, body.Number), heardFix{State: body.To, Why: body.Why, Merged: merged,
+		At: at, Class: body.Class, Opened: nonZero(body.Opened), MergedAt: nonZero(body.MergedAt)}, 0)
 	if err != nil {
 		return err
 	}
@@ -356,6 +404,24 @@ type Delivery struct {
 	Since time.Time
 	// Merged is the pull request's own merged flag, as the forge says it.
 	Merged bool
+	// Class, Opened and MergedAt are what a fix's time is read by (novox/hq ADR 0313), when the delivery says them.
+	Class    string
+	Opened   *time.Time
+	MergedAt *time.Time
+}
+
+// heard is what a delivery answered, as a fix keeps it.
+func (d Delivery) heard(since time.Time) heardFix {
+	return heardFix{State: d.State, Why: d.Why, Merged: d.Merged, At: since, Class: d.Class, Opened: d.Opened, MergedAt: d.MergedAt}
+}
+
+// nonZero is a moment said, or nil for one not said.
+func nonZero(t *time.Time) *time.Time {
+	if t == nil || t.IsZero() {
+		return nil
+	}
+	u := t.UTC()
+	return &u
 }
 
 // DeliveryState asks mesh-delivery for one pull request's delivery.
@@ -370,9 +436,12 @@ func busDeliveryState(owner string) DeliveryState {
 		}
 		var out struct {
 			Delivery struct {
-				State string    `json:"state"`
-				Waits string    `json:"waits"`
-				Since time.Time `json:"since"`
+				State    string     `json:"state"`
+				Waits    string     `json:"waits"`
+				Since    time.Time  `json:"since"`
+				Class    string     `json:"class"`
+				Opened   *time.Time `json:"opened"`
+				MergedAt *time.Time `json:"merged_at"`
 			} `json:"delivery"`
 			Pull struct {
 				Merged bool `json:"merged"`
@@ -381,7 +450,8 @@ func busDeliveryState(owner string) DeliveryState {
 		if err := json.Unmarshal(raw, &out); err != nil {
 			return Delivery{}, fmt.Errorf("mesh-delivery's checks answered no delivery: %.200s", raw)
 		}
-		return Delivery{State: out.Delivery.State, Why: out.Delivery.Waits, Since: out.Delivery.Since.UTC(), Merged: out.Pull.Merged}, nil
+		return Delivery{State: out.Delivery.State, Why: out.Delivery.Waits, Since: out.Delivery.Since.UTC(), Merged: out.Pull.Merged,
+			Class: out.Delivery.Class, Opened: nonZero(out.Delivery.Opened), MergedAt: nonZero(out.Delivery.MergedAt)}, nil
 	}
 }
 
@@ -430,7 +500,7 @@ func (t *Tracker) OnMoved(e stdio.Envelope) error {
 			if since.IsZero() {
 				since = t.now()
 			}
-			if _, err := t.recordFix(pr, state, d.Why, d.Merged, since, body.Number); err != nil {
+			if _, err := t.recordFix(pr, d.heard(since), body.Number); err != nil {
 				return err
 			}
 		}
@@ -481,6 +551,13 @@ func (t *Tracker) Sweep() (int, error) {
 	bound, now := t.stuckAfter(), t.now()
 	said := 0
 	for n, is := range all {
+		// A fix time missed at its delivery (a failure, or a restart between) is kept now; one of an issue moved to
+		// fixing before the tracker kept the moment is kept only when its fix is heard of again.
+		if is.FixingFrom != nil && is.FixTime == nil && allDelivered(is) {
+			if err := t.timeFix(n); err != nil {
+				t.Logf("[mesh-issues] the fix time of %d could not be kept (tried again at the next sweep): %v", n, err)
+			}
+		}
 		ok, err := t.sayNotResolved(is, now)
 		if err != nil {
 			t.Logf("[mesh-issues] that %d is delivered and not resolved could not be said on the operator's channel (said at the next sweep): %v", n, err)
@@ -537,5 +614,8 @@ func (t *Tracker) Sweep() (int, error) {
 			said++
 		}
 	}
+	if err := t.judgeFixBudgets(); err != nil {
+		t.Logf("[mesh-issues] a fix over its budget could not be said or cleared on the operator's channel (tried again at the next sweep): %v", err)
+	}
 	return said, nil
 }