[Docs] (P15): swap-interval stage, user decisions, and the FCL probe tools.

tools/device_bench/disagg/README.md

@@ -106,3 +106,31 @@ exits on EOF and RSTs the connection, and `pkill` must be anchored
 
 Attaches the device `/system/bin/strace` to the server's session child as the
 app uid via `run-as` (shell-uid ptrace is blocked).
+
+## P15 FCL probes: fcl_probe.sh, fcl_count.sh and their reducers
+
+`fcl_probe.sh <name> <lib> <backend> <transport> <outdir> [simpleperf=1]` swaps a library into
+FCL (rooted device), launches it, waits for steady in-world frames (MC's `Time elapsed:` line,
+then four fps-log windows of more than 150 frames each, relaunching on the known start-up death),
+then records:
+- 4 s of ftrace: sched, kgsl cmdbatch/waittimestamp, and atrace gfx for the app;
+- schedstat and `gpu_clock_stats` bracketing that window;
+- with the last argument at 1, 6 s of `simpleperf --trace-offcpu -p <game pid>`.
+
+The caller restores FCL with `fcl_p14.sh restore`. `fcl_count.sh` does the same launch for a
+`p15count.patch` build (per-draw (VAO, program) pair and between-draw entry statistics, armed by
+`debug.mobilegl.p15count=1` or `MOBILEGL_P15_COUNT=1`, window `MOBILEGL_P15_COUNT_WINDOW`).
+
+Reducers, all reading a probe directory:
+- `snapdiff.py`: per-thread CPU and runqueue wait;
+- `offwait.py <trace> <tid> <present-slice-regex>`: sleep and runnable time per frame, keyed by the
+  atrace slices open at switch-out and the waker, plus GPU busy;
+- `sfalign.py`: SurfaceFlinger `setTransactionState` duration and phase against `flushTransactions`;
+- `slices.py`: atrace slice totals per thread;
+- `fcl_split.py`: layer split, on- vs off-CPU;
+- `fcl_incl.py`: inclusive libMobileGL functions;
+- `fcl_drvcaller.py`: driver time by entry and MobileGL caller;
+- `fcl_stacks.py`: top stacks.
+
+The simpleperf reducers need `SIMPLEPERF_DIR` and a `binary_cache` from `binary_cache_builder.py`.
+Findings: `docs/Disaggregated/notes/perf-p15/PLAN-P15.md` section 2.

tools/device_bench/disagg/fcl_count.sh

@@ -0,0 +1,40 @@
+#!/usr/bin/env bash
+# fcl_count.sh <name> <hostlib> <backend> <transport> <outdir>
+# One FCL launch with a P15Count build (p15count.patch): waits for steady in-world frames, runs
+# 25 s with debug.mobilegl.p15count=1, and extracts the P15CNT lines to <outdir>/count.txt.
+# Caller restores FCL (fcl_p14.sh restore).
+set -u
+export MSYS_NO_PATHCONV=1 MSYS2_ARG_CONV_EXCL='*'
+name="$1" lib="$2" backend="$3" transport="$4" out="$5" sp="${6:-1}"
+SER=HA27Q3LQ FCL=com.tungsten.fcl.mgdebug.debug
+CFG=/data/data/$FCL/files/config.json
+mkdir -p "$out"
+su_sh() { adb -s $SER shell "su -c '$1'"; }
+dir=$(su_sh "dirname /data/app/*/$FCL-*/lib/arm64/libMobileGL.so" | tr -d '\r' | head -1)
+id=5e273ee2-baca-4c81-8e48-b63feefb9ba8; [ "$backend" = DirectVulkan ] && id=2be0dc10-1eef-4ce2-b512-b266dd33fd9e
+adb -s $SER push "$(cygpath -w "$lib")" /data/local/tmp/p15-fcl-lib.so >/dev/null
+su_sh "am force-stop $FCL; cat /data/local/tmp/p15-fcl-lib.so > $dir/libMobileGL.so; rm -f /data/local/tmp/p15-fcl-lib.so; md5sum $dir/libMobileGL.so" > "$out/libmd5.txt"
+su_sh "sh /data/local/tmp/p14-fcl-set.sh $id $CFG; setprop debug.mobilegl.fps_log 1; setprop debug.mobilegl.transport $transport; setprop debug.mobilegl.p15count 1"
+ok=0
+for attempt in 1 2 3 4; do
+  su_sh "am force-stop $FCL"; sleep 2
+  adb -s $SER logcat -c
+  su_sh "input keyevent KEYCODE_WAKEUP; monkey -p $FCL -c android.intent.category.LAUNCHER 1" >/dev/null 2>&1
+  t=0
+  while [ $t -lt 200 ]; do
+    sleep 3; t=$((t+3))
+    if [ $t -gt 12 ] && [ -z "$(adb -s $SER shell pidof $FCL | tr -dc '0-9')" ]; then echo "attempt $attempt: died at $t s" >> "$out/wait.txt"; break; fi
+    adb -s $SER logcat -d > "$out/logcat_wait.txt" 2>/dev/null
+    n=$(awk '/Time elapsed:/{f=1} f && /MobileGL fps:/{ if (match($0,/over [0-9]+ frames/)) { s=substr($0,RSTART+5,RLENGTH-12); if (s+0>150) c++ } } END{print c+0}' "$out/logcat_wait.txt")
+    if [ "$n" -ge 4 ]; then ok=1; break; fi
+  done
+  [ $ok = 1 ] && break
+done
+echo "waited=$t ok=$ok attempt=$attempt" >> "$out/wait.txt"
+[ $ok = 1 ] || { su_sh "am force-stop $FCL"; echo "NO STEADY FRAMES"; exit 3; }
+sleep 25
+adb -s $SER logcat -d > "$out/logcat.txt"
+su_sh "am force-stop $FCL; resetprop --delete debug.mobilegl.p15count"
+grep -a "P15CNT" "$out/logcat.txt" | sed 's/.*P15CNT/P15CNT/' > "$out/count.txt"
+grep -a "MobileGL fps:" "$out/logcat.txt" | tail -3 | sed 's/.*MobileGL fps: //'
+tail -12 "$out/count.txt"

tools/device_bench/disagg/fcl_drvcaller.py

@@ -0,0 +1,37 @@
+# fcl_drvcaller.py <rundir> <tid> <frames>: driver-layer on-CPU time keyed by (driver entry, MobileGL caller)
+import os, sys
+from collections import Counter
+sys.path.insert(0, os.environ.get("SIMPLEPERF_DIR", ""))
+sys.path.insert(0, os.path.dirname(os.path.abspath(__file__)))
+from simpleperf_report_lib import ReportLib
+from layers import layer_of
+d, tid, frames = sys.argv[1], int(sys.argv[2]), float(sys.argv[3])
+l = ReportLib(); l.SetRecordFile(os.path.join(d, "perf.data")); l.SetSymfs(os.path.join(d, "binary_cache"))
+c = Counter(); entry = Counter(); leafc = Counter()
+sh = lambda n: n.replace("(anonymous namespace)", "{anon}").split("(")[0][-60:]
+while True:
+    s = l.GetNextSample()
+    if s is None: break
+    if s.tid != tid: continue
+    leaf = l.GetSymbolOfCurrentSample(); cc = l.GetCallChainOfCurrentSample()
+    fr = [(leaf.symbol_name, leaf.dso_name)] + [(cc.entries[i].symbol.symbol_name, cc.entries[i].symbol.dso_name) for i in range(cc.nr)]
+    if any(n in ("__schedule", "schedule") or n.startswith("__switch_to") for n, _ in fr[:10]): continue
+    lay = None
+    for n, dso in fr:
+        lay = layer_of(n, dso)
+        if lay: break
+    if lay != "driver": continue
+    # outermost driver frame and the first MobileGL frame above it
+    last_drv = None; caller = "?"
+    for i, (n, dso) in enumerate(fr):
+        if layer_of(n, dso) == "driver": last_drv = i
+    if last_drv is not None:
+        e = sh(fr[last_drv][0]) + " [" + os.path.basename(fr[last_drv][1]) + "]"
+        for n, dso in fr[last_drv + 1:]:
+            if "libMobileGL" in dso: caller = sh(n); break
+            if "libgui" in dso or "libvulkan" in dso: caller = sh(n) + " [" + os.path.basename(dso) + "]"; break
+        c[(e, caller)] += s.period; entry[e] += s.period
+        leafc[sh(fr[0][0]) + " [" + os.path.basename(fr[0][1]) + "]"] += s.period
+print("driver entry (ms/frame):"); [print(f"  {v/1e6/frames:7.3f} {k}") for k, v in entry.most_common(15)]
+print("entry x caller:"); [print(f"  {v/1e6/frames:7.3f} {k[0]}  <- {k[1]}") for k, v in c.most_common(20)]
+print("leaf:"); [print(f"  {v/1e6/frames:7.3f} {k}") for k, v in leafc.most_common(12)]

tools/device_bench/disagg/fcl_incl.py

@@ -0,0 +1,28 @@
+# fcl_incl.py <rundir> <tid|thread comm> <frames> [N]: inclusive on-CPU ms/frame of libMobileGL functions
+import os, sys
+from collections import Counter
+sys.path.insert(0, os.environ.get("SIMPLEPERF_DIR", ""))
+from simpleperf_report_lib import ReportLib
+d, tid, frames = sys.argv[1], (int(sys.argv[2]) if sys.argv[2].isdigit() else sys.argv[2]), float(sys.argv[3]); N = int(sys.argv[4]) if len(sys.argv) > 4 else 60
+l = ReportLib(); l.SetRecordFile(os.path.join(d, "perf.data")); l.SetSymfs(os.path.join(d, "binary_cache"))
+incl = Counter(); selfc = Counter(); tot = 0
+sh = lambda n: n.replace("(anonymous namespace)", "{anon}").replace("MobileGL::", "").split("(")[0][-75:]
+while True:
+    s = l.GetNextSample()
+    if s is None: break
+    if (s.tid != tid) if isinstance(tid, int) else (tid not in s.thread_comm): continue
+    leaf = l.GetSymbolOfCurrentSample(); cc = l.GetCallChainOfCurrentSample()
+    fr = [(leaf.symbol_name, leaf.dso_name)] + [(cc.entries[i].symbol.symbol_name, cc.entries[i].symbol.dso_name) for i in range(cc.nr)]
+    if any(n in ("__schedule", "schedule") or n.startswith("__switch_to") for n, _ in fr[:10]): continue
+    tot += s.period
+    seen = set()
+    for n, dso in fr:
+        if "libMobileGL" in dso:
+            k = sh(n)
+            if k not in seen: incl[k] += s.period; seen.add(k)
+    for n, dso in fr:
+        if "libMobileGL" in dso: selfc[sh(n)] += s.period; break
+print(f"on-CPU {tot/1e6/frames:.3f} ms/frame")
+for k, v in incl.most_common(N): print(f"  {v/1e6/frames:7.3f} {k}")
+print("self (first MobileGL frame):")
+for k, v in selfc.most_common(25): print(f"  {v/1e6/frames:7.3f} {k}")

tools/device_bench/disagg/fcl_probe.sh

@@ -0,0 +1,59 @@
+#!/usr/bin/env bash
+# fcl_probe.sh <name> <hostlib> <backend> <transport> <outdir> [simpleperf=1]
+# One FCL launch: wait for steady in-world frames (fps log), then
+#  A) 4 s ftrace (sched + kgsl cmdbatch/waittimestamp + atrace gfx for the app), schedstat and gpu_clock_stats bracketing it
+#  B) 6 s simpleperf --trace-offcpu on the game pid (optional)
+# Caller restores FCL (fcl_p14.sh restore).
+set -u
+export MSYS_NO_PATHCONV=1 MSYS2_ARG_CONV_EXCL='*'
+name="$1" lib="$2" backend="$3" transport="$4" out="$5" sp="${6:-1}"
+SER=HA27Q3LQ FCL=com.tungsten.fcl.mgdebug.debug
+CFG=/data/data/$FCL/files/config.json
+mkdir -p "$out"
+su_sh() { adb -s $SER shell "su -c '$1'"; }
+dir=$(su_sh "dirname /data/app/*/$FCL-*/lib/arm64/libMobileGL.so" | tr -d '\r' | head -1)
+id=5e273ee2-baca-4c81-8e48-b63feefb9ba8; [ "$backend" = DirectVulkan ] && id=2be0dc10-1eef-4ce2-b512-b266dd33fd9e
+adb -s $SER push "$(cygpath -w "$lib")" /data/local/tmp/p15-fcl-lib.so >/dev/null
+su_sh "am force-stop $FCL; cat /data/local/tmp/p15-fcl-lib.so > $dir/libMobileGL.so; rm -f /data/local/tmp/p15-fcl-lib.so; md5sum $dir/libMobileGL.so" > "$out/libmd5.txt"
+su_sh "sh /data/local/tmp/p14-fcl-set.sh $id $CFG; setprop debug.mobilegl.fps_log 1; setprop debug.mobilegl.transport $transport"
+ok=0
+for attempt in 1 2 3 4; do
+  su_sh "am force-stop $FCL"; sleep 2
+  adb -s $SER logcat -c
+  su_sh "input keyevent KEYCODE_WAKEUP; monkey -p $FCL -c android.intent.category.LAUNCHER 1" >/dev/null 2>&1
+  t=0
+  while [ $t -lt 200 ]; do
+    sleep 3; t=$((t+3))
+    if [ $t -gt 12 ] && [ -z "$(adb -s $SER shell pidof $FCL | tr -dc '0-9')" ]; then echo "attempt $attempt: died at $t s" >> "$out/wait.txt"; break; fi
+    adb -s $SER logcat -d > "$out/logcat_wait.txt" 2>/dev/null
+    n=$(awk '/Time elapsed:/{f=1} f && /MobileGL fps:/{ if (match($0,/over [0-9]+ frames/)) { s=substr($0,RSTART+5,RLENGTH-12); if (s+0>150) c++ } } END{print c+0}' "$out/logcat_wait.txt")
+    if [ "$n" -ge 4 ]; then ok=1; break; fi
+  done
+  [ $ok = 1 ] && break
+done
+echo "waited=$t ok=$ok attempt=$attempt" >> "$out/wait.txt"
+[ $ok = 1 ] || { su_sh "am force-stop $FCL"; echo "NO STEADY FRAMES"; exit 3; }
+pid=$(adb -s $SER shell pidof $FCL | tr -d '\r' | awk '{print $NF}')
+echo "pid=$pid" >> "$out/wait.txt"
+snap() { adb -s $SER shell "su -c 'cat /proc/uptime; cat /sys/class/kgsl/kgsl-3d0/gpu_clock_stats; for t in /proc/$pid/task/*; do echo T \${t##*/} \$(cut -d\" \" -f1-3 \$t/schedstat) \$(cat \$t/comm); done'" > "$1"; }
+# A: ftrace
+EV=/sys/kernel/tracing/events
+su_sh "atrace --async_start -c -b 65536 -a $FCL gfx view sched freq >/dev/null 2>&1; for e in adreno_cmdbatch_submitted adreno_cmdbatch_retired kgsl_waittimestamp_entry kgsl_waittimestamp_exit adreno_syncobj_submitted adreno_syncobj_retired adreno_drawctxt_wait_start adreno_drawctxt_wait_done kgsl_timeline_wait; do echo 1 > $EV/kgsl/\$e/enable; done; echo 1 > $EV/sched/sched_waking/enable"
+snap "$out/snapA0.txt"
+sleep 4
+snap "$out/snapA1.txt"
+su_sh "atrace --async_stop -o /data/local/tmp/p15.atrace >/dev/null 2>&1; for e in adreno_cmdbatch_submitted adreno_cmdbatch_retired kgsl_waittimestamp_entry kgsl_waittimestamp_exit adreno_syncobj_submitted adreno_syncobj_retired adreno_drawctxt_wait_start adreno_drawctxt_wait_done kgsl_timeline_wait; do echo 0 > $EV/kgsl/\$e/enable; done; chmod 644 /data/local/tmp/p15.atrace"
+adb -s $SER pull /data/local/tmp/p15.atrace "$(cygpath -w "$out/trace.txt")" >/dev/null
+# B: simpleperf
+if [ "$sp" = 1 ]; then
+  snap "$out/snapB0.txt"
+  su_sh "rm -f /data/local/tmp/p15perf.data; simpleperf record -p $pid -e cpu-clock --trace-offcpu --call-graph fp -f 4000 --duration 6 -o /data/local/tmp/p15perf.data" > "$out/record.log" 2>&1
+  snap "$out/snapB1.txt"
+  su_sh "chmod 644 /data/local/tmp/p15perf.data"
+  adb -s $SER pull /data/local/tmp/p15perf.data "$(cygpath -w "$out/perf.data")" >/dev/null
+fi
+adb -s $SER logcat -d > "$out/logcat.txt"
+su_sh "am force-stop $FCL"
+grep -a "MobileGL fps:" "$out/logcat.txt" | tail -8 | sed 's/.*MobileGL fps: //' > "$out/fps.txt"
+echo "$name $backend $transport :: $(tail -4 "$out/fps.txt" | tr '\n' '|')"
+tail -1 "$out/record.log" 2>/dev/null

tools/device_bench/disagg/fcl_split.py

@@ -0,0 +1,45 @@
+# fcl_split.py <rundir> <tid> <ms_per_frame> [depth] [--detail=layer]
+# Period-weighted on/off-CPU split of one thread of an FCL simpleperf --trace-offcpu profile.
+# On-CPU goes to a layer (driver / backend / applier / client half / jvm+game / other), off-CPU is
+# grouped by its first user frames.
+import os, sys
+from collections import Counter
+sys.path.insert(0, os.environ.get("SIMPLEPERF_DIR", ""))
+sys.path.insert(0, os.path.dirname(os.path.abspath(__file__)))
+from simpleperf_report_lib import ReportLib
+from layers import layer_of
+args = [a for a in sys.argv[1:] if not a.startswith("--")]
+d, tid, mspf = args[0], int(args[1]), float(args[2]); depth = int(args[3]) if len(args) > 3 else 6
+detail = next((a.split("=", 1)[1] for a in sys.argv[1:] if a.startswith("--detail=")), None)
+l = ReportLib(); l.SetRecordFile(os.path.join(d, "perf.data")); l.SetSymfs(os.path.join(d, "binary_cache"))
+on = Counter(); off = Counter(); det = Counter(); t0 = t1 = None; ON = OFF = 0
+sh = lambda n: n.replace("(anonymous namespace)", "{anon}").split("(")[0][-60:]
+def lay(fr):
+    for n, dso in fr:
+        x = layer_of(n, dso)
+        if x == "harness": x = None
+        if x: return x
+    if any("libjvm" in dso or "jit" in dso.lower() or dso.endswith(".jar") or "dalvik" in dso or "[anon" in dso for _, dso in fr): return "jvm+game"
+    return "other"
+while True:
+    s = l.GetNextSample()
+    if s is None: break
+    if s.tid != tid: continue
+    t0 = s.time if t0 is None else t0; t1 = s.time
+    leaf = l.GetSymbolOfCurrentSample(); cc = l.GetCallChainOfCurrentSample()
+    fr = [(leaf.symbol_name, leaf.dso_name)] + [(cc.entries[i].symbol.symbol_name, cc.entries[i].symbol.dso_name) for i in range(cc.nr)]
+    if any(n in ("__schedule", "schedule") or n.startswith("__switch_to") for n, _ in fr[:10]):
+        OFF += s.period
+        user = [sh(n) for n, dso in fr if "kallsyms" not in dso and not dso.startswith("[")][:depth]
+        off[" <- ".join(user)] += s.period
+    else:
+        ON += s.period; L = lay(fr); on[L] += s.period
+        if detail and L == detail:
+            # first frame of that layer
+            for n, dso in fr:
+                if layer_of(n, dso) == detail: det[sh(n)] += s.period; break
+frames = (t1 - t0) / 1e6 / mspf
+print(f"tid {tid}: {frames:.0f} frames ({(t1-t0)/1e9:.2f}s at {mspf} ms/frame); on-CPU {ON/1e6/frames:.3f} ms/frame, off-CPU {OFF/1e6/frames:.3f}")
+for k, v in on.most_common(): print(f"  on  {v/1e6/frames:7.3f}  {k}")
+for k, v in off.most_common(16): print(f"  off {v/1e6/frames:7.3f}  {k[:230]}")
+for k, v in det.most_common(30): print(f"  det {v/1e6/frames:7.3f}  {k}")

tools/device_bench/disagg/fcl_stacks.py

@@ -0,0 +1,26 @@
+# fcl_stacks.py <rundir> <tid> <frames> [depth] [filter-substring]: on-CPU inclusive function time (ms/frame) and top stacks
+import os, sys
+from collections import Counter
+sys.path.insert(0, os.environ.get("SIMPLEPERF_DIR", ""))
+from simpleperf_report_lib import ReportLib
+d, tid, frames = sys.argv[1], int(sys.argv[2]), float(sys.argv[3]); depth = int(sys.argv[4]) if len(sys.argv) > 4 else 8
+flt = sys.argv[5] if len(sys.argv) > 5 else None
+l = ReportLib(); l.SetRecordFile(os.path.join(d, "perf.data")); l.SetSymfs(os.path.join(d, "binary_cache"))
+incl = Counter(); st = Counter(); offst = Counter()
+sh = lambda n: n.replace("(anonymous namespace)", "{anon}").split("(")[0][-55:]
+while True:
+    s = l.GetNextSample()
+    if s is None: break
+    if s.tid != tid: continue
+    leaf = l.GetSymbolOfCurrentSample(); cc = l.GetCallChainOfCurrentSample()
+    fr = [(leaf.symbol_name, leaf.dso_name)] + [(cc.entries[i].symbol.symbol_name, cc.entries[i].symbol.dso_name) for i in range(cc.nr)]
+    names = [sh(n) for n, _ in fr]
+    if flt and not any(flt in n for n in names): continue
+    if any(n in ("__schedule", "schedule") or n.startswith("__switch_to") for n, _ in fr[:10]):
+        u = [sh(n) for n, dso in fr if "kallsyms" not in dso and not dso.startswith("[")][:depth]
+        offst[" <- ".join(u)] += s.period; continue
+    for n in set(names): incl[n] += s.period
+    st[" <- ".join(names[:depth])] += s.period
+print("inclusive on-CPU:"); [print(f"  {v/1e6/frames:7.3f} {k}") for k, v in incl.most_common(40)]
+print("top on stacks:"); [print(f"  {v/1e6/frames:7.3f} {k[:300]}") for k, v in st.most_common(12)]
+print("top off stacks:"); [print(f"  {v/1e6/frames:7.3f} {k[:300]}") for k, v in offst.most_common(8)]

tools/device_bench/disagg/offwait.py

@@ -0,0 +1,73 @@
+# offwait.py <trace.txt> <tid> [present_marker]
+# Off-CPU accounting for one thread from an atrace/ftrace text dump:
+#  - sleep (S/D) and runnable (preempted) time per frame
+#  - sleep time keyed by the atrace slice stack open at the switch-out and the waker's comm
+#  - GPU busy from adreno_cmdbatch_retired (start/retire are GPU ticks: 19.2 MHz)
+import re, sys
+from collections import Counter, defaultdict
+path, tid = sys.argv[1], sys.argv[2]
+present = sys.argv[3] if len(sys.argv) > 3 else "QueuePresentKHR|eglSwapBuffers"
+pres_re = re.compile(present)
+line_re = re.compile(r'^\s*(.+?)-(\d+)\s+\(\s*([\d-]+)\)\s+\[(\d+)\]\s+\S+\s+([\d.]+):\s+(\w+):\s*(.*)$')
+stack = []
+state = None; t_state = None  # 'run' | 'sleep' | 'runq'
+sleep_by = Counter(); runq_total = 0.0; sleep_total = 0.0; run_total = 0.0
+pending_sleep = None  # (t0, stackkey, prev_state)
+last_waker = None
+presents = []
+gpu = []  # (start_tick, retire_tick, ctx)
+t_first = t_last = None
+slice_time = Counter(); slice_open = []
+for line in open(path, errors="replace"):
+    m = line_re.match(line)
+    if not m: continue
+    comm, pid, tgid, cpu, ts, ev, rest = m.groups(); ts = float(ts)
+    if t_first is None: t_first = ts
+    t_last = ts
+    if ev == "tracing_mark_write" and pid == tid:
+        if rest.startswith("B|"):
+            name = rest.split("|", 2)[2]
+            stack.append((name, ts))
+            if pres_re.search(name): presents.append(ts)
+        elif rest.startswith("E|"):
+            if stack:
+                name, t0 = stack.pop(); slice_time[name[:60]] += ts - t0
+    elif ev == "sched_waking":
+        mm = re.search(r'pid=(\d+)', rest)
+        if mm and mm.group(1) == tid: last_waker = f"{comm}"
+    elif ev == "sched_switch":
+        mp = re.search(r'prev_pid=(\d+) prev_prio=\d+ prev_state=(\S+) ==> next_comm=.* next_pid=(\d+)', rest)
+        if not mp: continue
+        ppid, pst, npid = mp.groups()
+        if ppid == tid:
+            key = " > ".join(n[:40] for n, _ in stack[-3:]) or "(no slice)"
+            pending_sleep = (ts, key, pst)
+            last_waker = None
+        if npid == tid and pending_sleep:
+            t0, key, pst = pending_sleep
+            d = ts - t0
+            if pst.startswith("R"): runq_total += d; sleep_by[("RUNNABLE(preempted)", key, "-")] += d
+            else: sleep_total += d; sleep_by[("sleep " + pst, key, last_waker or "?")] += d
+            pending_sleep = None
+    elif ev == "adreno_cmdbatch_retired":
+        ms = re.search(r'ctx=(\d+).*start=(\d+) retire=(\d+)', rest)
+        if ms: gpu.append((int(ms.group(2)), int(ms.group(3)), int(ms.group(1))))
+win = t_last - t_first
+# only steady presents
+nfr = max(1, len(presents) - 1); span = presents[-1] - presents[0] if len(presents) > 1 else win
+print(f"window {win:.3f}s, presents {len(presents)} -> {len(presents)/win:.1f} fps, frame {1e3*span/nfr:.3f} ms")
+print(f"per frame: sleep {1e3*sleep_total/nfr:.3f} ms, runnable(preempted) {1e3*runq_total/nfr:.3f} ms")
+print("top off-CPU (ms/frame): state | open slices at switch-out | waker")
+for (st, key, wk), d in sleep_by.most_common(18):
+    print(f"  {1e3*d/nfr:6.3f}  {st:<22} | {key[:110]:<110} | {wk}")
+print("top slices on thread (ms/frame, wall incl. children):")
+for k, v in slice_time.most_common(14): print(f"  {1e3*v/nfr:6.3f}  {k}")
+if gpu:
+    gpu.sort(); busy = 0; cs, ce = gpu[0][0], gpu[0][1]
+    for s, e, c in gpu[1:]:
+        if s > ce: busy += ce - cs; cs, ce = s, e
+        else: ce = max(ce, e)
+    busy += ce - cs
+    spanticks = gpu[-1][1] - gpu[0][0]
+    ctxs = Counter(c for _, _, c in gpu)
+    print(f"GPU: {len(gpu)} cmdbatches, busy {100*busy/spanticks:.1f}% of {spanticks/19.2e6:.2f}s, {1e3*busy/19.2e6/nfr:.3f} ms/frame; ctxs {ctxs.most_common(5)}")

tools/device_bench/disagg/p15count.patch

@@ -0,0 +1,239 @@
+diff --git a/MobileGL/MG_Impl/EGLImpl/EGLImpl.cpp b/MobileGL/MG_Impl/EGLImpl/EGLImpl.cpp
+index 45375ee4..4ab2cf50 100644
+--- a/MobileGL/MG_Impl/EGLImpl/EGLImpl.cpp
++++ b/MobileGL/MG_Impl/EGLImpl/EGLImpl.cpp
+@@ -57,6 +57,7 @@
+ #include <time.h>
+ #endif
+ 
++void P15CountFrame();
+ namespace MobileGL::MG_Impl::EGLImpl {
+     namespace {
+         // MOBILEGL_FPS_LOG=1 (on Android also the property debug.mobilegl.fps_log=1): one INFO line
+@@ -77,6 +78,7 @@ namespace MobileGL::MG_Impl::EGLImpl {
+         }
+ 
+         void NoteSwapForFrameRateLog() {
++            ::P15CountFrame();
+             if (!FrameRateLogEnabled()) return;
+             using Clock = std::chrono::steady_clock;
+             static Clock::time_point windowStart = Clock::now();
+diff --git a/MobileGL/MG_Impl/GLImpl/Exporting/Definitions.cpp b/MobileGL/MG_Impl/GLImpl/Exporting/Definitions.cpp
+index cc00326f..dfb56a3b 100644
+--- a/MobileGL/MG_Impl/GLImpl/Exporting/Definitions.cpp
++++ b/MobileGL/MG_Impl/GLImpl/Exporting/Definitions.cpp
+@@ -23,6 +23,7 @@
+ #include "../Debug/GL_Debug.h"
+ #include <MG_State/GLState/Core.h>
+ #include <MG_Impl/EGLImpl/EGLImpl.h>
++#include "P15Count.inl"
+ 
+ #define DECLARE_GL_FUNCTION_STUB_HEAD(type, name, ...) MOBILEGL_GL_API type gl##name(__VA_ARGS__) {
+ 
+@@ -53,12 +54,14 @@
+     }
+ #else
+ #define DECLARE_GL_FUNCTION_END(type, name, ...)                                                                       \
++    { static const int mglP15 = ::p15count::Reg(#name); ::p15count::Hit(mglP15); } \
+     MGLOG_D("Implementing function: %s(...)", __FUNCTION__);                                                           \
+     const MobileGL::MG_Impl::EGLImpl::GLStreamScope mglStreamScope;                                                    \
+     return MobileGL::MG_Impl::GLImpl::name(__VA_ARGS__);                                                               \
+     }
+ 
+ #define DECLARE_GL_FUNCTION_END_NO_RETURN(type, name, ...)                                                             \
++    { static const int mglP15 = ::p15count::Reg(#name); ::p15count::Hit(mglP15); } \
+     MGLOG_D("Implementing function: %s(...)", __FUNCTION__);                                                           \
+     const MobileGL::MG_Impl::EGLImpl::GLStreamScope mglStreamScope;                                                    \
+     MobileGL::MG_Impl::GLImpl::name(__VA_ARGS__);                                                                      \
+diff --git a/MobileGL/MG_Impl/GLImpl/Exporting/P15Count.inl b/MobileGL/MG_Impl/GLImpl/Exporting/P15Count.inl
+new file mode 100644
+index 00000000..1cb26c9a
+--- /dev/null
++++ b/MobileGL/MG_Impl/GLImpl/Exporting/P15Count.inl
+@@ -0,0 +1,186 @@
++// P15 MEASUREMENT ONLY (apply to a scratch tree, never merge into product code): per-draw (VAO, program) pair statistics and the GL entries
++// called between draws, to size the draw-packet cache. Armed by debug.mobilegl.p15count=1 or
++// MOBILEGL_P15_COUNT=1. One log line per 600 presented frames.
++#include <cstring>
++#include <cstdio>
++#include <cstdlib>
++#include <unordered_map>
++#include <vector>
++#include <algorithm>
++#if defined(__ANDROID__)
++#include <sys/system_properties.h>
++#endif
++namespace p15count {
++    using MobileGL::Uint64; using MobileGL::Uint32; using MobileGL::SizeT;
++    // categories: 0 free (draw, BindVertexArray, float uniform, UseProgram), 1 int uniform / block binding,
++    // 2 texture/sampler/image bind, 3 buffer bind/data/vertex setup, 4 texture data/params,
++    // 5 render state, 6 framebuffer/clear/blit, 7 other
++    constexpr int kCats = 8;
++    struct Fn { const char* name; int cat; bool draw; bool strictFree; };
++    inline std::vector<Fn>& Fns() { static std::vector<Fn> v; return v; }
++    inline bool On() {
++        static const bool on = [] {
++            const char* e = std::getenv("MOBILEGL_P15_COUNT");
++            if (e && e[0] == '1') return true;
++#if defined(__ANDROID__)
++            char p[PROP_VALUE_MAX] = {};
++            if (__system_property_get("debug.mobilegl.p15count", p) > 0 && p[0] == '1') return true;
++#endif
++            return false;
++        }();
++        return on;
++    }
++    inline bool Pre(const char* n, const char* p) { return std::strncmp(n, p, std::strlen(p)) == 0; }
++    inline bool IsFloatUniform(const char* n) {
++        if (Pre(n, "Program")) n += 7;
++        if (!Pre(n, "Uniform")) return false;
++        n += 7;
++        if (Pre(n, "BlockBinding")) return false;
++        const SizeT l = std::strlen(n);
++        if (l == 0) return false;
++        // ...f / ...fv
++        return n[l - 1] == 'f' || (l >= 2 && n[l - 2] == 'f' && n[l - 1] == 'v');
++    }
++    inline int Classify(const char* n, bool* draw, bool* strictFree) {
++        *draw = (Pre(n, "Draw") || Pre(n, "MultiDraw")) && !Pre(n, "DrawBuffer");
++        const bool fu = IsFloatUniform(n);
++        *strictFree = *draw || std::strcmp(n, "BindVertexArray") == 0 || fu;
++        if (*strictFree || std::strcmp(n, "UseProgram") == 0) return 0;
++        if (Pre(n, "Uniform") || Pre(n, "ProgramUniform")) return 1;
++        static const char* tex[] = {"BindTexture", "ActiveTexture", "BindSampler", "BindTextureUnit", "BindImageTexture"};
++        for (auto* t : tex) if (Pre(n, t)) return 2;
++        static const char* buf[] = {"BindBuffer", "BufferSubData", "BufferData", "NamedBuffer", "MapBuffer", "MapNamedBuffer",
++                                    "UnmapBuffer", "UnmapNamedBuffer", "FlushMapped", "VertexAttrib", "EnableVertexAttrib",
++                                    "DisableVertexAttrib", "BindVertexBuffer", "VertexBindingDivisor", "VertexArray",
++                                    "EnableVertexArrayAttrib", "DisableVertexArrayAttrib", "CopyBufferSubData", "ClearBuffer"};
++        for (auto* t : buf) if (Pre(n, t)) return 3;
++        static const char* td[] = {"TexImage", "TexSubImage", "TexParameter", "TextureParameter", "TexStorage", "TextureStorage",
++                                   "TextureSubImage", "GenerateMipmap", "GenerateTextureMipmap", "CopyTex", "CompressedTex", "PixelStore"};
++        for (auto* t : td) if (Pre(n, t)) return 4;
++        static const char* rs[] = {"Enable", "Disable", "Blend", "Depth", "ColorMask", "CullFace", "FrontFace", "Polygon", "Scissor",
++                                   "Viewport", "Stencil", "LineWidth", "PointSize", "SampleCoverage", "LogicOp", "ClipControl",
++                                   "PrimitiveRestart", "ProvokingVertex", "PatchParameter", "MinSampleShading", "SampleMask"};
++        for (auto* t : rs) if (Pre(n, t)) return 5;
++        static const char* fb[] = {"BindFramebuffer", "Framebuffer", "NamedFramebuffer", "DrawBuffer", "ReadBuffer", "Clear", "Blit",
++                                   "ReadPixels", "BindRenderbuffer", "Renderbuffer", "InvalidateFramebuffer", "InvalidateSubFramebuffer"};
++        for (auto* t : fb) if (Pre(n, t)) return 6;
++        return 7;
++    }
++    struct PairState { Uint64 lastFrame = ~0ull; Uint64 epoch[kCats] = {}; Uint64 strictEpoch = 0; Uint64 lastDraw = 0; };
++    struct St {
++        Uint64 frame = 0, frames = 0, draws = 0, calls = 0;
++        Uint64 epoch[kCats] = {};      // epoch[k] bumps on any call with category > k (k = allowed max category)
++        Uint64 strictEpoch = 0;        // bumps on anything outside {draw, BindVertexArray, float uniform}
++        Uint64 gapMask = 0;            // categories since the previous draw
++        bool gapStrictDirty = false;
++        std::vector<Uint32> gapFns; std::vector<Uint64> gapStamp; Uint64 gapGen = 1;
++        std::vector<Uint64> fnGapDraws;  // draws whose gap included fn
++        std::vector<Uint64> fnCalls;
++        std::unordered_map<Uint64, PairState> pairs; // key: vao lifetime * 2^24 ^ program lifetime
++        std::unordered_map<Uint64, Uint64> pairsThisFrame;
++        Uint64 prevPair = ~0ull;
++        Uint64 sameAsPrev = 0, seenThisFrame = 0, seenPrevFrame = 0, newEver = 0, distinctFrameSum = 0;
++        Uint64 hit[kCats] = {}, strictHit = 0, prevDrawClean[kCats] = {}, prevDrawStrictClean = 0;
++        Uint64 maskHist[256] = {};
++        Uint64 vaoZero = 0, progZero = 0;
++    };
++    inline St& S() { static St s; return s; }
++    inline int Reg(const char* name) {
++        bool d, sf; const int c = Classify(name, &d, &sf);
++        Fns().push_back({name, c, d, sf});
++        auto& s = S(); s.gapStamp.push_back(0); s.fnGapDraws.push_back(0); s.fnCalls.push_back(0);
++        return static_cast<int>(Fns().size() - 1);
++    }
++    inline void Hit(int idx) {
++        if (!On()) return;
++        auto& s = S(); const Fn& f = Fns()[idx];
++        ++s.calls; ++s.fnCalls[idx];
++        if (!f.draw) {
++            for (int k = 0; k < f.cat; ++k) ++s.epoch[k];
++            if (!f.strictFree) { ++s.strictEpoch; s.gapStrictDirty = true; }
++            s.gapMask |= 1ull << f.cat;
++            if (f.cat != 0 && s.gapStamp[idx] != s.gapGen) { s.gapStamp[idx] = s.gapGen; s.gapFns.push_back(idx); }
++            return;
++        }
++        // a draw: read the bound VAO and program before it runs
++        auto* ctx = MobileGL::MG_State::pGLContext.get();
++        if (!ctx) return;
++        const auto& vao = ctx->GetBoundVertexArray();
++        const auto& prog = ctx->GetCurrentProgram();
++        const Uint64 v = vao ? vao->GetLifetimeId() : 0, p = prog ? prog->GetLifetimeId() : 0;
++        if (!v) ++s.vaoZero;
++        if (!p) ++s.progZero;
++        const Uint64 key = (v << 24) ^ p;
++        ++s.draws;
++        if (key == s.prevPair) ++s.sameAsPrev;
++        s.prevPair = key;
++        auto [fit, fnew] = s.pairsThisFrame.emplace(key, 1);
++        if (!fnew) { ++s.seenThisFrame; ++fit->second; }
++        auto [it, isNew] = s.pairs.try_emplace(key);
++        PairState& ps = it->second;
++        if (isNew) ++s.newEver;
++        else {
++            if (ps.lastFrame + 1 == s.frame || ps.lastFrame == s.frame) ++s.seenPrevFrame;
++            for (int k = 0; k < kCats; ++k) if (ps.epoch[k] == s.epoch[k]) ++s.hit[k];
++            if (ps.strictEpoch == s.strictEpoch) ++s.strictHit;
++        }
++        for (int k = 0; k < kCats; ++k) ps.epoch[k] = s.epoch[k];
++        ps.strictEpoch = s.strictEpoch; ps.lastFrame = s.frame;
++        // gap since previous draw
++        int maxCat = 0; for (int k = 0; k < kCats; ++k) if (s.gapMask >> k & 1) maxCat = k;
++        for (int k = 0; k < kCats; ++k) if (maxCat <= k) ++s.prevDrawClean[k];
++        if (!s.gapStrictDirty) ++s.prevDrawStrictClean;
++        ++s.maskHist[s.gapMask & 255];
++        for (Uint32 i : s.gapFns) ++s.fnGapDraws[i];
++        s.gapFns.clear(); ++s.gapGen; s.gapMask = 0; s.gapStrictDirty = false;
++    }
++    inline void Frame() {
++        if (!On()) return;
++        auto& s = S();
++        s.distinctFrameSum += s.pairsThisFrame.size();
++        s.pairsThisFrame.clear();
++        ++s.frame; ++s.frames;
++        static const Uint64 kWin = [] { const char* w = std::getenv("MOBILEGL_P15_COUNT_WINDOW"); return w ? std::strtoull(w, nullptr, 10) : 600ull; }();
++        if (s.frames < kWin) return;
++        const double F = double(s.frames), D = s.draws ? double(s.draws) : 1.0;
++        MGLOG_I("P15CNT frames=%.0f draws/frame=%.1f glcalls/frame=%.1f distinctPairs/frame=%.1f pairsEver=%zu newPairs/frame=%.2f "
++                "sameAsPrev=%.1f%% seenThisFrame=%.1f%% seenPrevOrThisFrame=%.1f%% vao0=%.1f%% prog0=%.1f%%",
++                F, D / F, double(s.calls) / F, double(s.distinctFrameSum) / F, s.pairs.size(), double(s.newEver) / F,
++                100.0 * s.sameAsPrev / D, 100.0 * s.seenThisFrame / D, 100.0 * s.seenPrevFrame / D, 100.0 * s.vaoZero / D,
++                100.0 * s.progZero / D);
++        MGLOG_I("P15CNT strict(draw+BindVAO+floatUniform): pairEpochHit=%.1f%% prevDrawGapClean=%.1f%%", 100.0 * s.strictHit / D,
++                100.0 * s.prevDrawStrictClean / D);
++        for (int k = 0; k < kCats; ++k)
++            MGLOG_I("P15CNT allow<=cat%d: pairEpochHit=%.1f%% prevDrawGapClean=%.1f%%", k, 100.0 * s.hit[k] / D,
++                    100.0 * s.prevDrawClean[k] / D);
++        // top gap masks
++        std::vector<std::pair<Uint64, int>> mh;
++        for (int m = 0; m < 256; ++m) if (s.maskHist[m]) mh.push_back({s.maskHist[m], m});
++        std::sort(mh.rbegin(), mh.rend());
++        char line[1200]; int o = 0;
++        for (SizeT i = 0; i < mh.size() && i < 14 && o < 1100; ++i) o += std::snprintf(line + o, sizeof line - o, " %02x:%.1f%%", mh[i].second, 100.0 * mh[i].first / D);
++        MGLOG_I("P15CNT gapMasks(bit=cat):%s", line);
++        std::vector<std::pair<Uint64, int>> fg;
++        for (SizeT i = 0; i < s.fnGapDraws.size(); ++i) if (s.fnGapDraws[i]) fg.push_back({s.fnGapDraws[i], int(i)});
++        std::sort(fg.rbegin(), fg.rend());
++        o = 0;
++        for (SizeT i = 0; i < fg.size() && i < 24 && o < 1100; ++i)
++            o += std::snprintf(line + o, sizeof line - o, " %s(c%d):%.1f%%", Fns()[fg[i].second].name, Fns()[fg[i].second].cat, 100.0 * fg[i].first / D);
++        MGLOG_I("P15CNT gapFns(%% of draws):%s", line);
++        std::vector<std::pair<Uint64, int>> fc;
++        for (SizeT i = 0; i < s.fnCalls.size(); ++i) if (s.fnCalls[i]) fc.push_back({s.fnCalls[i], int(i)});
++        std::sort(fc.rbegin(), fc.rend());
++        o = 0;
++        for (SizeT i = 0; i < fc.size() && i < 30 && o < 1100; ++i)
++            o += std::snprintf(line + o, sizeof line - o, " %s:%.1f", Fns()[fc[i].second].name, double(fc[i].first) / F);
++        MGLOG_I("P15CNT calls/frame:%s", line);
++        // reset window counters (keep pair table and epochs)
++        s.frames = s.draws = s.calls = 0; s.sameAsPrev = s.seenThisFrame = s.seenPrevFrame = s.newEver = s.distinctFrameSum = 0;
++        s.strictHit = s.prevDrawStrictClean = s.vaoZero = s.progZero = 0;
++        for (int k = 0; k < kCats; ++k) s.hit[k] = s.prevDrawClean[k] = 0;
++        for (auto& m : s.maskHist) m = 0;
++        for (auto& x : s.fnGapDraws) x = 0;
++        for (auto& x : s.fnCalls) x = 0;
++    }
++}
++extern "C++" void P15CountFrame() { p15count::Frame(); }

tools/device_bench/disagg/sfalign.py

@@ -0,0 +1,26 @@
+# sfalign.py <trace>: does SF's setTransactionState return right after SF main-thread flushTransactions?
+import re, sys, bisect
+from collections import defaultdict
+line_re = re.compile(r'^\s*(.+?)-(\d+)\s+\(\s*([\d-]+)\)\s+\[(\d+)\]\s+\S+\s+([\d.]+):\s+tracing_mark_write:\s*(.*)$')
+st = defaultdict(list); ends = []; flush = []; begins = []
+for line in open(sys.argv[1], errors="replace"):
+    m = line_re.match(line)
+    if not m: continue
+    comm, pid, tgid, cpu, ts, rest = m.groups(); ts = float(ts)
+    if tgid.strip() != "1645": continue
+    if rest.startswith("B|"):
+        n = rest.split("|", 2)[2]; st[pid].append((n, ts))
+        if n.startswith("TransactionHandler:flushTransactions"): flush.append(ts)
+    elif rest.startswith("E|") and st[pid]:
+        n, s = st[pid].pop()
+        if n == "setTransactionState": ends.append(ts); begins.append(s)
+flush.sort(); d = []; w = []
+for b, e in zip(begins, ends):
+    i = bisect.bisect_right(flush, e) - 1
+    if i >= 0: d.append(1e3 * (e - flush[i]))
+    j = bisect.bisect_right(flush, b)
+    w.append(1e3 * (e - b))
+d.sort(); w.sort()
+q = lambda a, p: a[int(p * (len(a) - 1))]
+print(f"setTransactionState n={len(d)} duration ms p10/50/90 {q(w,.1):.2f}/{q(w,.5):.2f}/{q(w,.9):.2f}")
+print(f"end - last flushTransactions ms p10/50/90 {q(d,.1):.3f}/{q(d,.5):.3f}/{q(d,.9):.3f}; flush period {1e3*(flush[-1]-flush[0])/(len(flush)-1):.2f} ms")

tools/device_bench/disagg/slices.py

@@ -0,0 +1,16 @@
+# slices.py <trace> <comm-regex> : atrace slice wall time per slice name for threads whose comm-pid matches
+import re, sys
+from collections import Counter, defaultdict
+line_re = re.compile(r'^\s*(.+?)-(\d+)\s+\(\s*([\d-]+)\)\s+\[(\d+)\]\s+\S+\s+([\d.]+):\s+tracing_mark_write:\s*(.*)$')
+rx = re.compile(sys.argv[2]); stacks = defaultdict(list); tot = Counter(); cnt = Counter(); t0 = t1 = None
+for line in open(sys.argv[1], errors="replace"):
+    m = line_re.match(line)
+    if not m: continue
+    comm, pid, tgid, cpu, ts, rest = m.groups(); ts = float(ts)
+    t0 = ts if t0 is None else t0; t1 = ts
+    if not rx.search(comm + "-" + pid): continue
+    if rest.startswith("B|"):
+        stacks[pid].append((rest.split("|", 2)[2][:70], ts))
+    elif rest.startswith("E|") and stacks[pid]:
+        n, s = stacks[pid].pop(); tot[n] += ts - s; cnt[n] += 1
+for k, v in tot.most_common(25): print(f"{1e3*v:9.1f} ms  n={cnt[k]:6d}  avg {1e6*v/cnt[k]:8.1f} us  {k}")

tools/device_bench/disagg/snapdiff.py

@@ -0,0 +1,16 @@
+import sys
+def rd(p):
+    L=open(p).read().split('\n'); up=float(L[0].split()[0]); gpu=sum(int(x) for x in L[1].split())
+    T={}
+    for l in L[2:]:
+        f=l.split()
+        if len(f)>=5 and f[0]=='T': T[f[1]]=(int(f[2]),int(f[3]),int(f[4]),' '.join(f[5:]))
+    return up,gpu,T
+a=rd(sys.argv[1]); b=rd(sys.argv[2]); wall=b[0]-a[0]
+print(f"wall {wall:.2f}s gpu_clock_stats delta {(b[1]-a[1])/1e6:.3f} (units?) per wall-s {(b[1]-a[1])/wall/1e6:.3f}")
+rows=[]
+for k,v in b[2].items():
+    if k in a[2]:
+        u=a[2][k]; rows.append(((v[0]-u[0])/1e6,(v[1]-u[1])/1e6,v[2]-u[2],v[3],k))
+rows.sort(reverse=True)
+for r in rows[:12]: print(f"{r[3]:<22} tid {r[4]:>6} cpu {r[0]:8.1f} ms ({100*r[0]/1e3/wall:5.1f}%)  runq-wait {r[1]:7.1f} ms  switches {r[2]}")