From cd04e056db6eff994367babc44c2aef27ae91d7b Mon Sep 17 00:00:00 2001 From: angelrenefm <17342133+angelrenefm@users.noreply.github.com> Date: Fri, 16 Oct 2026 13:50:43 +0000 Subject: [PATCH] fix: droiddeckctl pacing judges cadence per refresh-rate record and always turns timestats off (#894) * fix: droiddeckctl pacing judges cadence per refresh-rate record and always turns timestats off Follow-up to the CodeRabbit reviews of #843/#855: - off-cadence is counted per layer record against that record's own cadence, allowing the neighbouring millisecond bucket (16.7 ms lands in 16 or 17); - refreshRates comes from the chosen layer records only; - records with no counted frames are skipped, so an empty game layer no longer hides the session's SurfaceView, and a capture with no frames exits NO_FRAMES; - adb failures while enabling or dumping map to PACING_FAILED, and timestats is disabled in every case. * fix: droiddeckctl pacing reports when timestats could not be turned off --- tools/droiddeckctl | 61 +++++++++++++++++++++----------- tools/tests/test_droiddeckctl.py | 59 ++++++++++++++++++++++++++++++ 2 files changed, 100 insertions(+), 20 deletions(-) diff --git a/tools/droiddeckctl b/tools/droiddeckctl index 65be5580c..e7a31c27d 100755 --- a/tools/droiddeckctl +++ b/tools/droiddeckctl @@ -300,27 +300,35 @@ def pacing_summary(text: str, package: str = PACKAGE) -> dict: frames shown, and 60 handed over can be 48 on screen with one in four held for two refreshes. """ records = {"game": [], "surface": []} - for part in re.split(r"^layerName = ", text, flags=re.M)[1:]: - name, _, body = part.partition("\n") + for part in re.split(r"^displayRefreshRate = ", text, flags=re.M)[1:]: + rate = re.match(r"(\d+)", part) + layer = re.search(r"^layerName = (.*)$", part, re.M) + frames = re.search(r"^totalFrames = (\d+)", part, re.M) + hist = re.search(r"^present2present histogram is as below:\n(.*)", part, re.M) + if not (rate and layer and frames and hist): + continue + name = layer.group(1) kind = ("game" if "droiddeck_wayland_game" in name else "surface" if f"SurfaceView[{package}/" in name else None) - frames = re.search(r"^totalFrames = (\d+)", body, re.M) - hist = re.search(r"^present2present histogram is as below:\n(.*)", body, re.M) - if kind and frames and hist: - records[kind].append((re.sub(r"#\d+$", "", name.strip()), int(frames.group(1)), hist.group(1))) + if kind and int(frames.group(1)): + bins = {int(ms): int(n) for ms, n in re.findall(r"(\d+)ms=(\d+)", hist.group(1)) if int(n)} + records[kind].append((re.sub(r"#\d+$", "", name.strip()), int(frames.group(1)), bins, int(rate.group(1)))) chosen = records["game"] or records["surface"] histogram: dict[int, int] = {} - for _, _, hist in chosen: - for ms, count in re.findall(r"(\d+)ms=(\d+)", hist): - if int(count): - histogram[int(ms)] = histogram.get(int(ms), 0) + int(count) + off = 0 + for _, _, bins, _ in chosen: + for ms, count in bins.items(): + histogram[ms] = histogram.get(ms, 0) + count + if bins: + # SurfaceFlinger bins by whole milliseconds, so one cadence spans two buckets (16.7 ms: 16 and 17). + mode = max(bins, key=bins.get) + off += sum(count for ms, count in bins.items() if abs(ms - mode) > 1) intervals = sum(histogram.values()) cadence = max(histogram, key=histogram.get) if histogram else None - off = intervals - histogram.get(cadence, 0) if histogram else 0 return { - "layers": sorted({name for name, _, _ in chosen}), - "frames": sum(frames for _, frames, _ in chosen), - "refreshRates": sorted({int(r) for r in re.findall(r"^displayRefreshRate = (\d+)", text, re.M)}), + "layers": sorted({name for name, _, _, _ in chosen}), + "frames": sum(frames for _, frames, _, _ in chosen), + "refreshRates": sorted({rate for _, _, _, rate in chosen}), "presentToPresentMs": {str(ms): histogram[ms] for ms in sorted(histogram)}, "cadenceMs": cadence, "offCadence": off, @@ -332,17 +340,30 @@ def pacing(adb: str, serial: str, seconds: float) -> dict: """Frames on screen and their intervals over `seconds`, from SurfaceFlinger's timestats.""" seconds = max(1.0, min(600.0, seconds)) timestats = ("shell", "dumpsys", "SurfaceFlinger", "--timestats") - if run_adb(adb, serial, *timestats, "-clear", "-enable").returncode != 0: + try: + enabled = run_adb(adb, serial, *timestats, "-clear", "-enable") + except ControlError as exc: + raise ControlError(str(exc), "PACING_FAILED") from exc + if enabled.returncode != 0: raise ControlError("could not enable SurfaceFlinger timestats", "PACING_FAILED") started = time.monotonic() - time.sleep(seconds) - dump = run_adb(adb, serial, *timestats, "-dump", timeout=60) - elapsed = time.monotonic() - started - run_adb(adb, serial, *timestats, "-disable") + try: + time.sleep(seconds) + dump = run_adb(adb, serial, *timestats, "-dump", timeout=60) + except ControlError as exc: + raise ControlError(str(exc), "PACING_FAILED") from exc + finally: + elapsed = time.monotonic() - started + try: + disabled = run_adb(adb, serial, *timestats, "-disable").returncode == 0 + except ControlError: + disabled = False if dump.returncode != 0: raise ControlError(dump.stderr.decode(errors="replace").strip() or "timestats dump failed", "PACING_FAILED") + if not disabled: + raise ControlError("could not turn SurfaceFlinger timestats off", "PACING_FAILED") summary = pacing_summary(dump.stdout.decode(errors="replace")) - if not summary["layers"]: + if not summary["layers"] or not summary["frames"]: raise ControlError("No DroidDeck layer drew during the capture: is a session on screen?", "NO_FRAMES") summary["fpsOnScreen"] = round(summary["frames"] / elapsed, 1) return {"ok": True, "command": "pacing", "seconds": round(elapsed, 1), **summary} diff --git a/tools/tests/test_droiddeckctl.py b/tools/tests/test_droiddeckctl.py index afb5cc218..2b0a554a6 100644 --- a/tools/tests/test_droiddeckctl.py +++ b/tools/tests/test_droiddeckctl.py @@ -305,6 +305,65 @@ class DroiddeckctlTest(FakeAdbTest): self.assertEqual(4, code) self.assertEqual("NO_FRAMES", out["error"]["code"]) + def test_pacing_counts_both_buckets_of_one_cadence_and_only_the_chosen_layers_rates(self): + text = "SurfaceFlinger TimeStats:\n" + "".join([ + timestats_record("droiddeck_wayland_game#7", 910, {16: 450, 17: 450, 33: 10}, 60), + timestats_record("StatusBar#106", 4, {8: 3}, 90), + ]) + summary = ctl.pacing_summary(text, "com.droiddeck.launcher") + self.assertEqual(10, summary["offCadence"]) + self.assertEqual([60], summary["refreshRates"]) + + def test_pacing_skips_a_game_layer_with_no_frames_for_the_surfaceview(self): + text = "SurfaceFlinger TimeStats:\n" + "".join([ + timestats_record("droiddeck_wayland_game#7", 0, {}, 120), + timestats_record("a1 SurfaceView[com.droiddeck.launcher/com.droiddeck.launcher.SessionActivity]#8", 600, {16: 598, 33: 1}, 120), + ]) + summary = ctl.pacing_summary(text, "com.droiddeck.launcher") + self.assertEqual(600, summary["frames"]) + self.assertIn("SurfaceView[com.droiddeck.launcher/", summary["layers"][0]) + + def test_pacing_with_a_layer_that_drew_no_frames_exits_4(self): + self.configure({}, timestats="SurfaceFlinger TimeStats:\n" + timestats_record("droiddeck_wayland_game#7", 0, {}, 120)) + with unittest.mock.patch.object(ctl.time, "sleep"): + code, out = self.run_ctl("pacing", "--seconds", "1") + self.assertEqual(4, code) + self.assertEqual("NO_FRAMES", out["error"]["code"]) + + def test_pacing_turns_timestats_off_when_the_dump_fails(self): + calls = [] + + def adb(_adb, _serial, *args, timeout=30): + calls.append(args[3:]) + if "-dump" in args: + raise ctl.ControlError("timed out", "ADB_FAILED") + return ctl.subprocess.CompletedProcess(args, 0, b"", b"") + + with unittest.mock.patch.object(ctl, "run_adb", adb), unittest.mock.patch.object(ctl.time, "sleep"): + with self.assertRaises(ctl.ControlError) as caught: + ctl.pacing("adb", "fake-1", 1) + self.assertEqual("PACING_FAILED", caught.exception.code) + self.assertEqual(("--timestats", "-disable"), calls[-1]) + + def test_pacing_fails_when_timestats_cannot_be_turned_off(self): + def adb(_adb, _serial, *args, timeout=30): + return ctl.subprocess.CompletedProcess(args, 1 if "-disable" in args else 0, b"", b"") + + with unittest.mock.patch.object(ctl, "run_adb", adb), unittest.mock.patch.object(ctl.time, "sleep"): + with self.assertRaises(ctl.ControlError) as caught: + ctl.pacing("adb", "fake-1", 1) + self.assertEqual("PACING_FAILED", caught.exception.code) + self.assertIn("timestats off", str(caught.exception)) + + def test_pacing_maps_an_adb_failure_while_enabling_to_pacing_failed(self): + def adb(*_args, **_kwargs): + raise ctl.ControlError("adb vanished", "ADB_FAILED") + + with unittest.mock.patch.object(ctl, "run_adb", adb): + with self.assertRaises(ctl.ControlError) as caught: + ctl.pacing("adb", "fake-1", 1) + self.assertEqual("PACING_FAILED", caught.exception.code) + def test_input_requests(self): self.configure({"input": {"ok": True, "command": "input"}}) self.run_ctl("input", "tap", "0.5", "0.25", "--space", "fraction")