130 lines
5.5 KiB
Markdown
130 lines
5.5 KiB
Markdown
---
|
||
id: 001-perf-timing-marks-105acc
|
||
title: Add startup, search and play timing marks plus yt-dlp duration logs
|
||
created: 2026-09-29
|
||
depends_on: []
|
||
est_files: 2
|
||
---
|
||
|
||
# 001 — Add startup, search and play timing marks plus yt-dlp duration logs
|
||
|
||
## Objective
|
||
|
||
Every later speed plan needs a before/after number. After this plan:
|
||
- The browser records `performance.measure` entries `ytp:boot`, `ytp:search`,
|
||
`ytp:tap-to-play`, and `window.__ytpPerf()` returns their latest values in ms.
|
||
- The server logs one line per yt-dlp call: `[ytdlp] <kind> <ms>ms ok|fail`.
|
||
|
||
Measured baseline (prod, 2026-09-29): search 4.1–5.0 s, first play `/api/streams` 7.5 s,
|
||
second play 1.2 s, `/api/version` 1.25 s.
|
||
|
||
## Context the executor must NOT rediscover
|
||
|
||
`server/server.js:143-165` — the only place yt-dlp is spawned:
|
||
|
||
```js
|
||
function runYtdlp(args, { signal } = {}) {
|
||
return new Promise((resolve, reject) => {
|
||
const child = spawn(YTDLP, args, { stdio: ['ignore', 'pipe', 'pipe'] });
|
||
...
|
||
child.on('error', (e) => reject(new Error('yt-dlp not found: ' + e.message)));
|
||
child.on('close', (code) => {
|
||
if (code !== 0) reject(new Error(err.trim() || 'yt-dlp exited with code ' + code));
|
||
else resolve(out);
|
||
});
|
||
});
|
||
}
|
||
```
|
||
|
||
`frontend/app.js`:
|
||
- `async function boot()` starts at ~line 9749 (`wirePlayerEvents();` is its first line).
|
||
The first `render()` call inside boot happens after the `hasShareParam` block.
|
||
- `async function runSearchQuery(q, { instant = null } = {})` at ~line 8583; the
|
||
success path ends with `RecentSearches.cacheResults(q, results);`.
|
||
- `Player.loadVideo(videoObj, …)` at ~line 1650; first statement is
|
||
`if (!this._handoff) Transition.cancel();`.
|
||
- The master element `playing` listener at ~line 2287:
|
||
```js
|
||
el.addEventListener('playing', () => {
|
||
if (!masterIs(el)) return;
|
||
showSpinner(false);
|
||
```
|
||
|
||
## Steps
|
||
|
||
1. `server/server.js` — in `runYtdlp`, directly after the `const child = spawn(...)` line add:
|
||
```js
|
||
const t0 = Date.now();
|
||
const kind = String(args.find((a) => /^ytsearch|^https?:/.test(String(a))) || args[0] || '')
|
||
.replace(/^ytsearch\d*:.*/, 'search').replace(/^https?:\/\/[^/]+\/watch.*/, 'video').slice(0, 40);
|
||
```
|
||
and replace the `child.on('close', …)` handler body with:
|
||
```js
|
||
child.on('close', (code) => {
|
||
console.log(`[ytdlp] ${kind} ${Date.now() - t0}ms ${code === 0 ? 'ok' : 'fail'}`);
|
||
if (code !== 0) reject(new Error(err.trim() || 'yt-dlp exited with code ' + code));
|
||
else resolve(out);
|
||
});
|
||
```
|
||
2. `frontend/app.js` — near the top of the file, directly after the line
|
||
`const APP_VERSION = '1.0.0';` (~line 24), add:
|
||
```js
|
||
// Timing marks for the speed work (plans/). performance.measure entries are
|
||
// visible in DevTools → Performance; __ytpPerf() prints the latest ones.
|
||
function perfMark(name) { try { performance.mark(name); } catch { /* old browser */ } }
|
||
function perfMeasure(name, start) {
|
||
try { performance.measure(name, start); } catch { /* start mark missing */ }
|
||
}
|
||
window.__ytpPerf = () => {
|
||
const out = {};
|
||
try { for (const m of performance.getEntriesByType('measure')) if (m.name.startsWith('ytp:')) out[m.name] = Math.round(m.duration); } catch { /* none */ }
|
||
return out;
|
||
};
|
||
```
|
||
3. `frontend/app.js` `boot()` — first line of the function body: `perfMark('ytp:boot-start');`.
|
||
Immediately after the FIRST `render();` call inside `boot()` add
|
||
`perfMeasure('ytp:boot', 'ytp:boot-start');`.
|
||
4. `frontend/app.js` `runSearchQuery` — after `const mySeq = ++searchSeq;` add
|
||
`perfMark('ytp:search-start');`. After `RecentSearches.cacheResults(q, results);` add
|
||
`perfMeasure('ytp:search', 'ytp:search-start');`.
|
||
5. `frontend/app.js` `Player.loadVideo` — first line of the body: `perfMark('ytp:tap');`.
|
||
6. `frontend/app.js` master `playing` listener — after `if (!masterIs(el)) return;` add:
|
||
```js
|
||
if (performance.getEntriesByName('ytp:tap').length) {
|
||
perfMeasure('ytp:tap-to-play', 'ytp:tap');
|
||
try { performance.clearMarks('ytp:tap'); } catch { /* ignore */ }
|
||
}
|
||
```
|
||
|
||
## Out of scope / do NOT touch
|
||
|
||
- No reporting endpoint, no UI. Don't change any behaviour, only add marks/logs.
|
||
- Do not touch `runYtdlpResilient` or the fallback-client logic.
|
||
|
||
## Verification
|
||
|
||
```bash
|
||
cd /home/user/ytplayer && node --check frontend/app.js && cd server && bun build server.js --target=bun --outdir=/tmp/ytp-check >/dev/null && echo SERVER_OK
|
||
cd /home/user/ytplayer && node --test frontend/*.test.js 2>&1 | tail -3
|
||
grep -c "perfMark\|perfMeasure" frontend/app.js
|
||
```
|
||
|
||
Expected: no syntax errors, `SERVER_OK`, tests `fail 0`, grep count ≥ 8.
|
||
|
||
## Report format (executor: follow exactly)
|
||
|
||
Output ONLY the following, no other prose:
|
||
|
||
1. `git diff` (unified) of all changes.
|
||
2. Raw output of the Verification commands.
|
||
3. `Findings:` — max 10 lines: surprises, deviations from the steps, anything
|
||
skipped and why.
|
||
|
||
Do not commit. Do not push. Do not touch files outside the Steps.
|
||
|
||
## Execution log
|
||
|
||
- Executor: in-session Agent (haiku), gateway `delegate.sh` not installed. Attempts: 1. Fix rounds: 0.
|
||
- Orchestrator re-ran Verification: syntax OK, `SERVER_OK`, `node --test frontend/*.test.js` 52 pass / 0 fail, mark count 8.
|
||
- Executor Findings (verbatim): All 6 plan steps applied successfully. Frontend timing marks added for boot (start->first paint), search (start->cached), tap-to-play (tap->playing event). Server logs yt-dlp duration on every invocation. Verification: syntax OK, server builds, unit tests pass (0 failures), 8 perfMark/perfMeasure occurrences (exceeds required 8). No deviations or skips.
|