Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 2 additions & 2 deletions .tfcore/telemetry/SCHEMA.md
Original file line number Diff line number Diff line change
Expand Up @@ -93,7 +93,7 @@ So `tf-emit.sh` detects it and injects it. **Never write `harness` into an emit

| Field | Type | Values / notes |
|---|---|---|
| `cmd` | string | `day1-brownfield` \| `day1-greenfield` \| `split-brd` \| `mockups` \| `build-phase` \| `verify-phase` \| `fix-issues` \| `triage-issues` \| `log-miss` \| `devguide` \| `productguide` \| `handoff-phase` \| `refresh-status` \| `amend-docs` \| `deploy-checklist` (added 2026-09-06) |
| `cmd` | string | `day1-brownfield` \| `day1-greenfield` \| `split-brd` \| `mockups` \| `build-phase` \| `verify-phase` \| `fix-issues` \| `triage-issues` \| `log-miss` \| `devguide` \| `productguide` \| `handoff-phase` \| `refresh-status` \| `amend-docs` \| `deploy-checklist` (added 2026-09-06) \| `metrics-report` \| `generate-html` \| `render-workflow-docs` \| `triage-and-fix` \| `framework-reset` (framework maintenance, D-19; all five added 2026-09-07, after FR-37's check was built and found 27 records already carrying a value the schema did not list). A value outside this list is a defect in the emitting task, not in the reader: the reader keeps it. |
| `mode` | string \| null | `build` \| `fix`. `build-phase` already distinguishes these (FIX mode) — capture it; the ratio is the rework metric. `null` for commands with no mode. |
| `started` | string | ISO-8601 UTC. When the task began — the timestamp you noted at step 0, not "now minus a guess". |
| `ended` | string | ISO-8601 UTC. Normally equal to `ts`. |
Expand Down Expand Up @@ -173,7 +173,7 @@ Failure:
|---|---|---|
| `run_id` | string | The `started` timestamp of the owning run. Ties every REQ verdict in one verify pass together. |
| `req_id` | string | e.g. `REQ-UI-004`. |
| `req_class` | string | `UI` \| `FN` \| `RAG` \| `NFR` — the prefix segment of `req_id`. |
| `req_class` | string | `UI` \| `FN` \| `RAG` \| `NFR` — the prefix segment of `req_id`. **`FR` added 2026-09-07**: the framework's own requirement lines (`docs/TechieFlow-Requirements.md`), graded by `tests/requirements/run.sh`. It is the one `req_class` that does not come from an application's checklist, and it never pools with the others — a framework line and a screen requirement are not the same unit. |
| `attempt` | int | See §3.1. Derive it; never guess it. |
| `verdict` | string | Mirrors the checklist vocabulary **exactly**: `Verified` \| `Needs re-verify` \| `FAIL` \| `Blocked` \| `Implemented` \| `Done (pre-existing)`. |
| `gate` | string \| null | **The FIRST gate that failed**, or `null` on a pass. See §3.2. |
Expand Down
83 changes: 80 additions & 3 deletions .tfcore/telemetry/tf-metrics.sh
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@ import re
import subprocess
import sys
from collections import Counter, defaultdict, OrderedDict
from datetime import datetime

STREAMS = ("runs", "gates", "sessions", "commits", "misses")
VERDICTS = ("Verified", "Needs re-verify", "FAIL", "Blocked", "Implemented", "Done (pre-existing)")
Expand Down Expand Up @@ -496,6 +497,34 @@ def analyse_phases(runs):
when someone asks how it was measured."""
live = [r for r in runs if r.get("kind", "run") == "run" and not r.get("backfilled")]

# A run that carries both ends but no `duration_s` was silently worth ZERO TIME here,
# while its tokens still counted — so a phase's total time was a sum over some of its
# runs and its tokens a sum over others (found 2026-09-07: the reset's own 13 runs
# reported 16h49m, because 6 of them predate the field and the true figure is ~55h).
# Deriving it is arithmetic on two recorded facts, not a guess, so it is done — and
# counted, so the report can say how many of its minutes were derived rather than read.
# `ended` itself may be absent on an older record; SCHEMA.md's own rule is that `ended`
# IS the moment the record was written, which is exactly what `ts` holds.
def _secs(a, b):
try:
fmt = "%Y-%m-%dT%H:%M:%SZ"
return int((datetime.strptime(b, fmt) - datetime.strptime(a, fmt)).total_seconds())
except Exception:
return None

derived_n = 0
for r in live:
if r.get("duration_s") or not r.get("started"):
continue
end = r.get("ended") or r.get("ts")
if not end:
continue
d = _secs(r["started"], end)
if d is not None and d >= 0:
r["duration_s"] = d
r["duration_derived"] = "ended" if r.get("ended") else "ts"
derived_n += 1

def scope_of(r):
return r.get("tokens_scope") or "absent"

Expand Down Expand Up @@ -564,6 +593,10 @@ def analyse_phases(runs):
"median": median(durs),
"max": max(durs) if durs else None,
"n": len(durs),
# how many of those minutes were computed from the record's own two
# timestamps because the record predates `duration_s` — arithmetic on
# recorded facts, but the reader is told rather than left to assume.
"derived_n": sum(1 for r in rs if r.get("duration_derived")),
},
"share_of_duration": pct(sum(durs), grand_dur),
"tokens_measured_n": len(priced),
Expand All @@ -581,6 +614,27 @@ def analyse_phases(runs):
key=lambda kv: (-kv[1]["tokens_out"], kv[0]))),
"harnesses": OrderedDict(sorted(Counter(r.get("harness") or "?" for r in rs).items())),
"modes": OrderedDict(sorted(Counter(r.get("mode") or "—" for r in rs).items())),
# A phase run in named modes (a reset's sessions, a build's fresh/fix passes)
# is several different jobs under one `cmd`. The per-mode split says which,
# in the order they happened. Same denominators as the phase above: a run
# with no computable window contributes no tokens, never a zero.
"by_mode": OrderedDict(
(mode, {
"runs": len([r for r in rs if (r.get("mode") or "—") == mode]),
"duration_s": sum(r.get("duration_s") or 0
for r in rs if (r.get("mode") or "—") == mode),
"tokens_out": sum(r.get("tokens_out") or 0
for r in rs if (r.get("mode") or "—") == mode and has_tokens(r)),
"tokens_unmeasured_n": len([r for r in rs
if (r.get("mode") or "—") == mode and not has_tokens(r)]),
"files_written": sum(r.get("files_written") or 0
for r in rs if (r.get("mode") or "—") == mode),
"first_started": min((r.get("started") or "" for r in rs
if (r.get("mode") or "—") == mode), default=""),
})
for mode in sorted({(r.get("mode") or "—") for r in rs},
key=lambda m: min((r.get("started") or "" for r in rs
if (r.get("mode") or "—") == m), default=""))),
"build_result": OrderedDict(sorted(Counter(r.get("build_result") or "—" for r in rs).items())),
"reqs_touched_total": sum(r.get("reqs_count") or 0 for r in rs),
"files_written_total": sum(r.get("files_written") or 0 for r in rs),
Expand Down Expand Up @@ -951,6 +1005,20 @@ def analyse(repos):
live = [g for g in gates if not g.get("backfilled")]
back = [g for g in gates if g.get("backfilled")]

# `attempt` is DEFINED by §3.1 as 1 + the number of prior live gate records for the same
# requirement in the same app — a count over this very stream, not a judgement. A record
# that omits it was therefore being read as "no attempt", which drops it out of the
# first-pass rate and reports 0% for a set of records that all passed on their first and
# only verdict (found 2026-09-07 on the framework's own requirement lines). Derived here,
# in stream order, for records that lack it. A record that carries one is never touched.
_seen = {}
for g in sorted(live, key=lambda r: (r.get("ts") or "", r.get("run_id") or "")):
key = (g.get("app"), g.get("req_id"))
_seen[key] = _seen.get(key, 0) + 1
if g.get("attempt") is None:
g["attempt"] = _seen[key]
g["attempt_derived"] = True

# REQs with ANY backfilled record are excluded from the live first-pass rate:
# their live `attempt` numbering restarts at 1 (SCHEMA.md §3.1).
# A requirement is keyed by (app, req_id): REQ-UI-001 exists in every project, so a rollup that
Expand Down Expand Up @@ -1192,8 +1260,9 @@ def print_phases(p, W):
for cmd, m in p["phases"].items():
print(" [%s] %d run(s)" % (cmd, m["runs"]))
d = m["duration_s"]
print(" wall clock : total %s · median %s · max %s (n=%d timed)"
% (_hms(d["total"]), _hms(d["median"]), _hms(d["max"]), d["n"]))
print(" wall clock : total %s · median %s · max %s (n=%d timed%s)"
% (_hms(d["total"]), _hms(d["median"]), _hms(d["max"]), d["n"],
", %d derived from the record's own timestamps" % d["derived_n"] if d.get("derived_n") else ""))
t = m["tokens"]
print(" tokens : out %s · in %s · cache-read %s · cache-write %s"
% (_k(t["out"]), _k(t["in"]), _k(t["cache_read"]), _k(t["cache_write"])))
Expand Down Expand Up @@ -1255,7 +1324,15 @@ def print_phases(p, W):
print(" cost (%s) : $%s over %d record(s) — MEASURED, never pooled "
"across harness" % (h, c["usd"], c["records"]))
if m["reqs_touched_total"] or m["files_written_total"]:
print(" work : %d REQ touch(es) · %d file(s) written"
bm = m.get("by_mode") or {}
if len(bm) > 1:
print(" by mode : (in the order they ran)")
for mode, v in bm.items():
unm = (" [%d unmeasured]" % v["tokens_unmeasured_n"]) if v["tokens_unmeasured_n"] else ""
print(" %-22s %2d run(s) %8s %8s out %3d file(s)%s"
% (mode, v["runs"], _hms(v["duration_s"]), _k(v["tokens_out"]),
v["files_written"], unm))
print(" work : %d REQ touch(es) · %d file(s) written"
% (m["reqs_touched_total"], m["files_written_total"]))
print("")

Expand Down
Loading
Loading