From 42eab64880f62330fb0b5365184d26c64fab77f9 Mon Sep 17 00:00:00 2001 From: harsha balakrishnan Date: Wed, 14 Oct 2026 11:27:25 +0530 Subject: [PATCH] docs(perf): Rank P1 hypotheses from CLT profiles xctrace needs full Xcode and powermetrics needs sudo, so this pass uses top, footprint, sample, heap, and vmmap. Muted audio is the largest playing cost; paused playback keeps CoreMedia and IOSurface. Idle CPU is already 0.0% with the 20 s battery timer still firing once. --- CHANGELOG.md | 1 + docs/PERFORMANCE.md | 21 +++++- docs/PERFORMANCE_MASTER_PLAN.md | 12 ++-- docs/perf-findings.md | 114 ++++++++++++++++++++++++-------- scripts/perf/README.md | 10 +-- scripts/perf/measure.sh | 18 +++++ 6 files changed, 135 insertions(+), 41 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index b4c1048..9d0fcb7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -34,6 +34,7 @@ All notable changes to Lively are documented here. The format follows [Keep a Ch - New CI workflow runs build, tests, and packaging on every push and pull request. - Performance harness: `os_signpost` intervals, `scripts/perf/measure.sh`, generated fixtures. No runtime behaviour change unless `LIVELY_PERF_MODE` is set. - Measure isolation: `LIVELY_APPLICATION_SUPPORT` and `LIVELY_CONFIG_FILE` redirect Application Support. Setting `HOME` does not move `userDomainMask` on current macOS. +- `scripts/perf/measure.sh` also records `heap` (top by size) and `vmmap --summary`. ## [1.2.0] - 2026-07-14 diff --git a/docs/PERFORMANCE.md b/docs/PERFORMANCE.md index 8e16074..dac63ab 100644 --- a/docs/PERFORMANCE.md +++ b/docs/PERFORMANCE.md @@ -81,8 +81,25 @@ still has `figThreadMain` waiting on Fig semaphores. RAM is inside the idle/playing/paused budgets. Playing CPU is **above** the 1.5% budget once decode is up (~5.7% of one core on this 30 s window). Paused RAM stays ~6 MB above idle with CoreMedia threads still -resident — a **hint** for hypothesis B, not a P1 confirmation. Paused -CPU is not a clean 0.0 on this window. +resident — P1 confirmed this as hypothesis B. + +## P1 fixture comparison (2026-10-14) + +Same host and isolated harness as P0. `sample` / `heap` / `vmmap` added. +Popover closed. One 5K built-in display. JSON prefix `20261014T05`. + +| Run | CPU avg (steady) | `footprint` | vs 1080p30 HEVC silent | +|---|---|---|---| +| Idle 45 s | 0.0 | 15 MB | — | +| 1080p30 HEVC silent | 4.367 (5.1–5.6) | 21 MB | baseline | +| 1080p30 HEVC audio, muted | 13.7 (14.8–17.7) | 47 MB | +9.3% CPU, +26 MB | +| 4K60 HEVC silent | 7.033 (7.8–8.9) | 26 MB | +2.7% CPU, +5 MB | +| 1080p30 H.264 silent | 4.217 (4.7–5.5) | 21 MB | ~same as HEVC | +| Paused 1080p30 HEVC | 0.017 | 19 MB | +4 MB vs idle | + +1080p30 HEVC silent already misses the 1.5% playing budget (~5.2% of one +core in AVFoundation). A muted audio track triples that. Ranking and +A–N verdicts: `docs/perf-findings.md`. ### Not measured here (need the operator) diff --git a/docs/PERFORMANCE_MASTER_PLAN.md b/docs/PERFORMANCE_MASTER_PLAN.md index f732f30..5dd8c53 100644 --- a/docs/PERFORMANCE_MASTER_PLAN.md +++ b/docs/PERFORMANCE_MASTER_PLAN.md @@ -159,9 +159,9 @@ Exit: playing CPU and Energy Impact meet budget on the 1080p30 fixture; the 4K60 - If a hypothesis in section 1 is disproved by profiling, say so in `docs/perf-findings.md` and skip the item. - Stop and ask the owner before: changing minimum macOS version, removing a user-facing setting, or any rewrite of a module larger than ~300 lines. -## 5. Expected payoff (ranked, to be confirmed by P1) -1. P4 transcode to native-size 30 fps HEVC plus audio strip: largest CPU, GPU and Energy gain while playing. -2. P3 cold pause and lazy popover: largest RAM gain while idle or paused. -3. P2 removal of the 20 s timer and other wake-ups: removes the constant idle drain. -4. P4 shared player across displays and seamless loop: removes loop spikes and halves multi-display decode. -5. P6 build flags: smaller binary and faster launch, modest runtime effect. +## 5. Expected payoff (ranked by P1 — see `docs/perf-findings.md`) +1. P4 / H disable audio tracks when muted: muted AAC fixture was 13.7% CPU / 47 MB vs 4.4% / 21 MB silent. +2. P4 / J cap or transcode to 1080p30 (not 5K-native): 4K60 was ~8.6% CPU and 466 MB IOSurface virtual. +3. P3 / B cold pause: paused keeps CoreMedia threads and ~82 MB IOSurface virtual. +4. P2 / A, E, F wake-ups: 20 s timer confirmed; idle `top` already 0.0%; energy needs sudo. +5. P3 / C lazy popover, then P4 G/K, then P5/P6. diff --git a/docs/perf-findings.md b/docs/perf-findings.md index 06966d7..5c55aba 100644 --- a/docs/perf-findings.md +++ b/docs/perf-findings.md @@ -1,32 +1,88 @@ # Perf findings -Hypothesis table (A–N) lives in `docs/PERFORMANCE_MASTER_PLAN.md` §1. P1 -must confirm or refute each item with Instruments. Until then, treat the -table as unread code, not measured fact. - -## P0 (this branch) - -- Finder/iCloud `* 2.*` duplicates removed (byte-identical except - `Lively-task-list-plan 2.md`, which was an older copy of the tracked file). -- Dependabot `actions/checkout` 4 → 7 merged on `master` as #8 (CI green). -- Signposts: `launch`, `synchronize`, `playerBuild`, `pause`, `resume` - (`com.lively.app` / `Performance`). -- `scripts/perf/measure.sh` writes JSON under `perf/results/`. Null fields - mean the sampler did not run. Do not fill them in by hand. +Hypothesis table (A–N) lives in `docs/PERFORMANCE_MASTER_PLAN.md` §1. This +file is the ranked, measured list. Do not start P2 until the ranking below +is the source of truth. + +## How P1 was measured (2026-10-14) + +Host: Apple M1, macOS 27.0.1, one built-in 5K display (5120×2880, also +listed as 2560×1600 scaled). Release `.app` from `./package.sh` (CLT). +Isolated Application Support (`LIVELY_APPLICATION_SUPPORT` / +`LIVELY_CONFIG_FILE`). Popover closed. User `config_v2.json` checksum +unchanged (`2558921003 1531`). + +Tools that **did** run: `top`, `footprint`, `sample(1)`, `heap -sH` (first +120 lines), `vmmap --summary`. JSON under `perf/results/20261014T05*`. + +Tools that **did not** run: + +| Tool | Why | Exact command | +|---|---|---| +| Instruments Time Profiler / Allocations / Energy Log / System Trace | `xctrace` needs full Xcode; `xcode-select -p` is Command Line Tools | `xctrace record --template 'Time Profiler' --time-limit 30s --output /tmp/lively-time.trace --attach ` | +| `powermetrics` | needs sudo | `sudo powermetrics --samplers tasks --show-process-energy --show-process-wait-times -i 1000 -n 30 --process-name Lively` | +| `os_signpost` durations | unified log (`/usr/bin/log show --predicate 'subsystem == "com.lively.app"'`) was empty without a trace session | same `xctrace` Time Profiler / `os_signpost` template | +| Popover open, Space switch, display hot-plug | no UI automation; one display | do by hand with the commands above attached | + +Do not fill Energy Impact or idle-wake-ups from imagination. They stay `—`. + +## Fixture comparison (playing, 30 s `top` after settle) + +| Fixture | CPU avg (last five) | `footprint` | Threads | Notes | +|---|---|---|---|---| +| Idle (no wallpaper), 45 s | 0.0 (all 9 samples) | 15 MB | 9 → 3 | CFRunLoop wait | +| 1080p30 HEVC silent | 4.367 (5.1–5.6) | 21 MB | 24–28 | budget clip | +| 1080p30 HEVC **audio**, muted | 13.7 (14.8–17.7) | 47 MB (peak 49) | 31–43 | AudioToolbox IOProc | +| 4K60 HEVC silent | 7.033 (7.8–8.9) | 26 MB (peak 28) | 21–25 | IOSurface 466 MB virtual | +| 1080p30 H.264 silent | 4.217 (4.7–5.5) | 21 MB | 20–29 | same ballpark as HEVC | +| Paused (1080p30 HEVC) | 0.017 | 19 MB (peak 21) | 8–13 | CoreMedia threads still there | + +Idle 45 s `sample(1)` (25 s): one `__NSFireTimer` → Lively timer thunk +(hypothesis A). Playing silent `sample`: AVPlayer / CoreMedia, almost no +AudioToolbox. Playing audio `sample`: `AQMEIO_HAL::IOProc`, +`AudioConverterFillComplexBuffer`, `AudioUnitRender`. Paused `sample`: +`figThreadMain` on `coremedia.imagequeue` / `videomediaconverter` / +`videomentor`. `vmmap`: idle has no IOSurface region; paused keeps ~82 MB +IOSurface virtual; 4K playing maps 466 MB IOSurface virtual. + +## A–N verdicts + +| # | Verdict | Evidence | Next phase | +|---|---|---|---| +| **H** | **Confirmed, largest playing delta** | Muted audio fixture 13.7% CPU / 47 MB vs silent 4.4% / 21 MB. `player.isMuted = true` still builds the audio graph. `WallpaperSession.loadVideo` never disables `AVPlayerItemTrack`s. | P4 | +| **J** | **Confirmed** | 4K60 silent 7.0% avg (~8.6% steady) / 26 MB vs 1080p30 4.4% / 21 MB. IOSurface virtual 466 MB vs 79 MB. This 5K panel would make a naive “display-native” transcode *larger* than 4K; cap to `maxResolution` / 1080p, not 5120×2880. | P4 | +| **B** | **Confirmed** | `pause()` only `player.pause()`. Paused keeps Fig queues, ~82 MB IOSurface virtual, +4 MB phys vs idle (19 vs 15). | P3 | +| Decode floor | **Measured** | 1080p30 HEVC silent steady ~5.2% of one core, all in AVFoundation. Budget is 1.5%. Rust will not move this. Shrinking the stream (H, J) or the loop (G) is the lever. | P4 | +| **A** | **Confirmed, idle CPU already 0.0%** | `Timer.scheduledTimer(20)` in `setupBatteryMonitor`. 25 s idle sample captured one `__NSFireTimer`. `top` idle 0.0% for 45 s. Wake-ups / energy still unknown without sudo. | P2 | +| **C** | **Confirmed in code; RAM not dominant** | `NSHostingController` assigned at launch (`main.swift`). SwiftUI/AttributeGraph mapped while idle. Heap top-120 is CFString/dictionaries, not view graphs. Popover-open delta not measured. | P3 | +| **G** | **Code confirmed; spike size unknown** | `seek(to: .zero)` on item end, 2 s fixture. 5 s `top` samples stay ~5% with no visible loop spike (averaging hides it). | P4 after H/J | +| **K** | **Confirmed in code** | Wallpaper path never reads `NSWorkspace.accessibilityDisplayShouldReduceMotion`. UI chrome does. | P4 | +| **E** | **Confirmed in code, not profiled** | `configStore.$configs` always `retryFailedPlayback()` + `spaceMonitor.refresh()`. | P2 | +| **F** | **Confirmed in code, not profiled** | Space change polls 10×50 ms even with no assignment. | P2 | +| **I** | **Untested** | One display. | P4 if a second display exists | +| **D** | **Confirmed in code, not in heap top** | `LogStore` `@Published` cap 1000. Not a top allocator at idle. | P3, after B/C | +| **L** | **Confirmed in code, trivial** | `DateFormatter` in `AppMetrics`, once a day. Not on-CPU in samples. | P5 | +| **M** | **Partial** | Ephemeral `URLSession` already; still launch-time if opted in. Default is off; perf harness skips it. | P5 | +| **N** | **Confirmed** | Executable 4,366,496 bytes. `package.sh` is `swift build -c release` with no `-Osize` / strip. | P6 | + +## Ranked next work + +1. **P4 / H** — when muted, disable audio `AVPlayerItemTrack`s (or strip on import). Biggest measured CPU and RAM win on files that have a soundtrack. Default wallpaper is muted. +2. **P4 / J** — transcode or cap to 1080p30 (honour `maxResolution`). 4K60 is already ~1.6× the 1080p30 CPU and a much larger IOSurface. Do not transcode up to 5K. +3. **P3 / B** — cold pause: tear down the player after a grace period, poster frame in the layer, no black flash. Confirmed retained CoreMedia + IOSurface while paused. +4. **P2 / A, E, F** — drop the 20 s timer and the always-on config/space refresh. Idle CPU is already 0.0%; this is for wake-ups and energy, which still need `sudo powermetrics`. +5. **P3 / C** — lazy popover. Launch already builds SwiftUI; idle 15 MB is inside the 20 MB budget, so this is smaller than B. +6. **P4 / G, K** — looper and Reduce Motion after H/J. +7. **P5 / P6** — L, M, N. + +P2 remains the next *named phase* in the master plan. Measured impact says **H before A** if the goal is playing CPU and battery. Wait for an explicit go-ahead before either. + +## P0 (previous branch) + +- Finder/iCloud `* 2.*` duplicates removed. +- Dependabot `actions/checkout` 4 → 7 merged on `master` as #8. +- Signposts: `launch`, `synchronize`, `playerBuild`, `pause`, `resume`. - Isolation: `HOME` does not move `userDomainMask`. Harness sets - `LIVELY_APPLICATION_SUPPORT`, `LIVELY_CONFIG_FILE`, and a throwaway - `com.lively.app.perf` UserDefaults suite. `sample(1)` is captured when - present (CLT; no Xcode). -- Canonical baseline is the isolated 30 s run in `docs/PERFORMANCE.md`. - Playing CPU (~5.7% once decode is up) misses the 1.5% budget. Paused - footprint 20 MB vs idle 14 MB, with `figThreadMain` still waiting — - treat as a **hint** for hypothesis B, not a P1 confirmation. Wake-ups - and Energy Impact were not sampled (powermetrics needs sudo). -- Earlier same-day tables that used `HOME` only are invalid. One leaked - run wrote the fixture into the real `config_v2.json`; isolation is now - a P0 correctness requirement. - -## P1 (not started) - -See the P1 plan in the P0 pull request. Do not skip. Do not start P2 until -this file records a ranked, measured list. + `LIVELY_APPLICATION_SUPPORT`, `LIVELY_CONFIG_FILE`, throwaway + `com.lively.app.perf` UserDefaults. +- Canonical idle/playing/paused budget table: `docs/PERFORMANCE.md`. diff --git a/scripts/perf/README.md b/scripts/perf/README.md index b051e1a..997d837 100644 --- a/scripts/perf/README.md +++ b/scripts/perf/README.md @@ -41,10 +41,12 @@ launches the bundle executable (not via `open`) with: the real user Library on current macOS. Without the `LIVELY_*` overrides the harness writes the live config. -Samples `top`, `footprint`, and `sample(1)` (CLT). Writes -`perf/results/--.json`. Playing and paused assign the -1080p30 HEVC fixture to every visible Space; they cover the desktop until -the script stops the process. +Samples `top`, `footprint`, `sample(1)`, `heap -sH` (first 120 lines), and +`vmmap --summary` (CLT). Writes `perf/results/--.json`. +Playing and paused assign the 1080p30 HEVC fixture to every visible Space +unless `LIVELY_PERF_FIXTURE` is set; they cover the desktop until the +script stops the process. Duration ≥ 40 s uses a 25 s `sample` so the +20 s battery timer can show up. ### powermetrics (sudo) diff --git a/scripts/perf/measure.sh b/scripts/perf/measure.sh index 0abfb02..9ed5ba4 100755 --- a/scripts/perf/measure.sh +++ b/scripts/perf/measure.sh @@ -119,6 +119,9 @@ top -l "$TOP_SAMPLES" -s 5 -pid "$PID" -stats pid,cpu,mem,rsize,threads \ SAMPLE_SECS=10 if [[ "$DURATION" -lt 15 ]]; then SAMPLE_SECS=5 +elif [[ "$DURATION" -ge 40 ]]; then + # Long enough to catch the 20 s battery Timer (hypothesis A). + SAMPLE_SECS=25 fi if command -v sample >/dev/null 2>&1; then echo "measure: sample ${SAMPLE_SECS}s of pid $PID" @@ -133,6 +136,19 @@ else echo "measure: footprint failed (see $RAW_DIR/footprint.err)" fi +if command -v heap >/dev/null 2>&1; then + echo "measure: heap (top by size)" + heap -sH "$PID" 2>"$RAW_DIR/heap.err" | python3 -c ' +import sys +lines = sys.stdin.readlines() +sys.stdout.writelines(lines[:120]) +' > "$RAW_DIR/heap-top.txt" || true +fi +if command -v vmmap >/dev/null 2>&1; then + echo "measure: vmmap --summary" + vmmap --summary "$PID" > "$RAW_DIR/vmmap-summary.txt" 2>"$RAW_DIR/vmmap.err" || true +fi + POWERMETRICS_ERROR="" if command -v powermetrics >/dev/null 2>&1; then if sudo -n true 2>/dev/null; then @@ -159,6 +175,7 @@ MEASURE_STAMP="$STAMP" MEASURE_COMMIT="$COMMIT" MEASURE_MODE="$MODE" \ MEASURE_DURATION="$DURATION" MEASURE_PID="$PID" MEASURE_CHIP="$CHIP" \ MEASURE_OS="$OS_VER" MEASURE_BIN="$BINARY_BYTES" \ MEASURE_POWER_ERR="$POWERMETRICS_ERROR" MEASURE_RAW="$RAW_DIR" MEASURE_JSON="$JSON" \ +MEASURE_FIXTURE="${FIXTURE:-}" \ python3 <<'PY' import json, os, re from pathlib import Path @@ -216,6 +233,7 @@ payload = { "energy_impact": None, "idle_wakeups_per_s": None, "raw_dir": str(raw_dir), + "fixture": os.environ.get("MEASURE_FIXTURE") or None, "notes": [ "Energy Impact is Activity Monitor / Instruments Energy Log; not sampled here.", "Idle wake-ups need powermetrics or Activity Monitor.",