adding ftime

.github/scripts/perf_comment.py

@@ -32,6 +32,30 @@ def fmt_delta(pct):
     return f"{sign}{value}%"
 
 
+def fmt_share(value, total):
+    if total <= 0:
+        return "n/a"
+    return f"{value / total * 100:.0f}%"
+
+
+def is_significant(m):
+    return abs(m["delta_pct"]) >= THRESHOLDS.get(m["method"], 0.1)
+
+
+# Stage rows (frontend/backend) shown as base%/head% shares of their group.
+def breakdown(children):
+    base_total = sum(c["base"] for c in children)
+    head_total = sum(c["head"] for c in children)
+    if head_total <= 0:
+        return []
+    return ["| ↳ {} | {} | {} | {} |".format(
+        c["label"],
+        fmt_share(c["base"], base_total),
+        fmt_share(c["head"], head_total),
+        fmt_delta(c["delta_pct"]),
+    ) for c in children]
+
+
 def render(results):
     lines = [
         MARKER,
@@ -40,13 +64,19 @@ def render(results):
         "| Metric | Base | PR | delta |",
         "|--------|------|----|-------|",
     ]
-    for m in results["metrics"]:
+    metrics = results["metrics"]
+    for m in metrics:
+        if m.get("parent"):
+            continue
         lines.append("| {} | {} | {} | {} |".format(
             m["label"],
             fmt_value(m["base"], m["unit"]),
             fmt_value(m["head"], m["unit"]),
             fmt_delta(m["delta_pct"]),
         ))
+        children = [c for c in metrics if c.get("parent") == m["id"]]
+        if children and is_significant(m):
+            lines += breakdown(children)
     return "\n".join(lines) + "\n"
 
 
@@ -89,8 +119,7 @@ def main():
         return
 
     significant = any(
-        abs(m["delta_pct"]) >= THRESHOLDS.get(m["method"], 0.1)
-        for m in results["metrics"]
+        is_significant(m) for m in results["metrics"] if not m.get("parent")
     )
     if not significant:
         print("all deltas within noise threshold, skipping comment")

tools/perfrunner/source/app.d

@@ -55,7 +55,7 @@ int main(string[] args)
 
     MetricResult[] metrics;
     foreach (def; initials)
-        metrics ~= MetricResult(def.id, def.label, def.unit, def.method,
+        metrics ~= MetricResult(def.id, def.label, def.unit, def.method, def.parent,
             base[def.id], head[def.id]);
 
     auto rep = Report(baseSha, "merge-base", headSha, pr, os, hostDmd, metrics);

tools/perfrunner/source/metrics.d

@@ -8,13 +8,15 @@ import std.regex : ctRegex, matchFirst;
 import std.process : execute;
 
 import cachegrind : instructions;
+import timetrace : stages;
 
 struct MetricDef
 {
     string id;
     string label;
     string unit;
     string method;
+    string parent; // headline metric this row breaks down, empty for top-level rows
 }
 
 // Some initial metrics to measure will add more later
@@ -26,6 +28,8 @@ immutable MetricDef[] initials = [
     MetricDef("hello_binary_size",           "hello binary size",          "bytes", "stat"),
     MetricDef("hello_max_rss",               "peak RSS (compile hello.d)", "kb",    "time -v"),
     MetricDef("phobos_max_rss",              "peak RSS (compile Phobos)",  "kb",    "time -v"),
+    MetricDef("phobos_stage_frontend", "frontend (parse+sema)",     "us", "time-trace", "compile_phobos_instr"),
+    MetricDef("phobos_stage_backend",  "backend (inline+codegen)",  "us", "time-trace", "compile_phobos_instr"),
 ];
 
 // Measure every metric for one dmd binary. `tag` ("base"/"head")
@@ -34,7 +38,7 @@ long[string] measure(string dmd, string workload, string phobos, string tmp, str
 {
     auto stdPackage = buildPath(phobos, "std", "package.d");
     auto phobosFlags = ["-i=std", "-preview=dip1000"];
-    return [
+    long[string] m = [
         "compile_hello_debug_instr":   instructions(dmd, [], workload, tmp, tag ~ "-dbg"),
         "compile_hello_release_instr": instructions(dmd, ["-O", "-release"], workload, tmp, tag ~ "-rel"),
         "compile_phobos_instr":        instructions(dmd, phobosFlags, stdPackage, tmp, tag ~ "-phobos"),
@@ -43,6 +47,13 @@ long[string] measure(string dmd, string workload, string phobos, string tmp, str
         "hello_max_rss":               maxRss(dmd, [], workload, tmp, tag),
         "phobos_max_rss":              maxRss(dmd, phobosFlags, stdPackage, tmp, tag ~ "-phobos"),
     ];
+
+    // Stage breakdown of the Phobos compile. Zero on a base too old for
+    // -ftime-trace; the comment renders that side as n/a.
+    auto st = stages(dmd, phobosFlags, stdPackage, tmp, tag ~ "-phobos");
+    m["phobos_stage_frontend"] = st.get("stage_frontend_us", 0);
+    m["phobos_stage_backend"]  = st.get("stage_backend_us", 0);
+    return m;
 }
 
 // Byte size of `binary`

tools/perfrunner/source/report.d

@@ -11,6 +11,7 @@ struct MetricResult
     string label;
     string unit;
     string method;
+    string parent;
     long base;
     long head;
 }
@@ -32,19 +33,22 @@ string render(Report rep)
     JSONValue[] metrics;
     foreach (m; rep.metrics)
     {
-        metrics ~= JSONValue([
+        JSONValue[string] obj = [
             "id":        JSONValue(m.id),
             "label":     JSONValue(m.label),
             "unit":      JSONValue(m.unit),
             "method":    JSONValue(m.method),
             "base":      JSONValue(m.base),
             "head":      JSONValue(m.head),
             "delta_pct": JSONValue(round(deltaPct(m.base, m.head) * 100) / 100.0),
-        ]);
+        ];
+        if (m.parent.length)
+            obj["parent"] = JSONValue(m.parent);
+        metrics ~= JSONValue(obj);
     }
 
     JSONValue root = [
-        "schema_version": JSONValue(1),
+        "schema_version": JSONValue(2),
         "base":   JSONValue(["sha": JSONValue(rep.baseSha), "ref": JSONValue(rep.baseRef)]),
         "head":   JSONValue(["sha": JSONValue(rep.headSha), "pr": JSONValue(rep.pr)]),
         "runner": JSONValue(["os": JSONValue(rep.os), "host_dmd": JSONValue(rep.hostDmd)]),
@@ -58,10 +62,10 @@ unittest
 {
     auto rep = Report("base1", "merge-base", "head1", 7, "ubuntu-latest", "2.112.0",
         [MetricResult("compile_hello_debug_instr", "compile hello.d (instr)",
-            "count", "cachegrind", 1000, 1010)]);
+            "count", "cachegrind", "", 1000, 1010)]);
 
     auto j = parseJSON(render(rep));
-    assert(j["schema_version"].integer == 1);
+    assert(j["schema_version"].integer == 2);
     assert(j["base"]["sha"].str == "base1");
     assert(j["head"]["pr"].integer == 7);
     assert(j["metrics"].array.length == 1);

tools/perfrunner/source/timetrace.d

@@ -0,0 +1,60 @@
+module timetrace;
+
+import std.algorithm : canFind;
+import std.file : readText;
+import std.json : parseJSON;
+import std.path : buildPath;
+import std.process : execute;
+
+// The top-level -ftime-trace spans grouped into frontend/backend. These names
+// match main.d's generic phase spans; they don't overlap, so summing them
+// partitions the compile without double-counting the nested per-symbol events.
+private immutable string[] frontendSpans = ["Parsing", "Semantic analysis"];
+private immutable string[] backendSpans  = ["Inlining", "Code generation"];
+
+// Sum the duration (microseconds) of the top-level spans in each bucket.
+long[string] parseStages(string trace)
+{
+    long frontend, backend;
+    foreach (e; parseJSON(trace)["traceEvents"].array)
+    {
+        if (e["ph"].str != "X")
+            continue;
+        auto name = e["name"].str;
+        if (frontendSpans.canFind(name))
+            frontend += e["dur"].integer;
+        else if (backendSpans.canFind(name))
+            backend += e["dur"].integer;
+    }
+    return ["stage_frontend_us": frontend, "stage_backend_us": backend];
+}
+
+// Compile the workload with -ftime-trace and read the per-stage durations.
+// Returns null if the compiler is too old to know the flag (older base side).
+long[string] stages(string dmd, string[] dflags, string workload, string tmp, string tag)
+{
+    auto obj = buildPath(tmp, tag ~ "-tt.o");
+    auto trace = buildPath(tmp, tag ~ ".time-trace");
+    auto cmd = [dmd, "-c", "-ftime-trace", "-ftime-trace-file=" ~ trace]
+        ~ dflags ~ [workload, "-of=" ~ obj];
+    if (execute(cmd).status != 0)
+        return null;
+    return parseStages(readText(trace));
+}
+
+unittest
+{
+    auto sample = `{"traceEvents": [
+        {"ph":"M","name":"process_name"},
+        {"ph":"X","name":"Parsing","dur":100},
+        {"ph":"X","name":"Parse: Module foo","dur":40},
+        {"ph":"X","name":"Semantic analysis","dur":300},
+        {"ph":"X","name":"Sema1: Function bar","dur":50},
+        {"ph":"X","name":"Inlining","dur":20},
+        {"ph":"X","name":"Code generation","dur":80},
+        {"ph":"X","name":"Codegen: function bar","dur":30}
+    ]}`;
+    auto s = parseStages(sample);
+    assert(s["stage_frontend_us"] == 400);
+    assert(s["stage_backend_us"] == 100);
+}