From 9a86003b128d7840c80a13ce3c9a932e07c79213 Mon Sep 17 00:00:00 2001 From: Joel Dickson Date: Wed, 5 Aug 2026 11:22:19 +0700 Subject: [PATCH] Extend devfeedback to the whole local dev cycle Every event this package produced described one compilation, so the number a developer actually feels -- git pull to a working app -- was unanswerable, and in dev mode time to a usable dev server was not measured at all because closeBundle never fires. Adds a `type: "command"` event with an install, devserver or clientready phase, a sessionId on every event type so those phases stitch into one timeline, and install capture for npm, yarn and pnpm. Aborted runs are recorded too: Ctrl-C produces a devserver event with `signal` set, without changing what Ctrl-C does. Nothing here may sit on the critical path, which is most of the design: - install and signal-handler events are spooled to a local NDJSON file and delivered by the next dev server or build, so an install never waits on the network and a dying process never loses the race - 1500 ms timeout on every POST, so an off-VPN developer never hangs - git metadata is cached until the repository actually changes, replacing three synchronous git spawns per HMR event - the session id is resolved once per process; its keepalive touch is deferred, leaving the HMR path with no synchronous filesystem writes - stats.toJson() no longer serializes the whole compilation on every rebuild - startup chatter moved behind DEVFEEDBACK_DEBUG Install capture has two tiers. The default needs no repo change and infers the duration from the package manager's process start time. A preinstall/postinstall pair in the consuming repo upgrades it to an exact span with a trustworthy coldInstall flag; when those are present the bundled hook stands down, so one event is produced rather than two. measurementSource records which route was used, because the inferred one systematically undercounts and the two must not be aggregated together. Also fixes rsbuild and rspack posting to the webpack endpoint, contradicting the README, and widens the Vite peer range to >=4.0.0. packages/webpack-plugin is deliberately untouched. Closes #46. Ingestion-side schema changes are tracked in #47. Co-Authored-By: Claude Opus 5 (1M context) --- .changeset/whole-dev-cycle.md | 15 ++ README.md | 97 +++++++++- examples/command.json | 169 ++++++++++++++++++ packages/common/package.json | 8 +- packages/common/src/hooks/postinstall.ts | 95 ++++++++++ packages/common/src/hooks/preinstall.ts | 46 +++++ packages/common/src/index.ts | 32 +++- packages/common/src/lib/common.ts | 68 ++++--- packages/common/src/lib/debug.ts | 21 +++ packages/common/src/lib/git.spec.ts | 72 ++++++++ packages/common/src/lib/git.ts | 111 ++++++++++++ packages/common/src/lib/install.spec.ts | 114 ++++++++++++ packages/common/src/lib/install.ts | 155 ++++++++++++++++ packages/common/src/lib/npm-timing.ts | 120 +++++++++++++ packages/common/src/lib/session.spec.ts | 126 +++++++++++++ packages/common/src/lib/session.ts | 137 ++++++++++++++ packages/common/src/lib/signals.ts | 47 +++++ packages/common/src/lib/spool.spec.ts | 96 ++++++++++ packages/common/src/lib/spool.ts | 85 +++++++++ packages/common/src/lib/types.ts | 55 ++++++ packages/common/tsup.config.ts | 10 +- packages/common/vite.config.ts | 13 ++ .../src/lib/rsbuild-stats-plugin.spec.ts | 67 ++++++- .../src/lib/rsbuild-stats-plugin.ts | 124 +++++++++++-- .../src/lib/rspack-stats-plugin.spec.ts | 6 + .../src/lib/rspack-stats-plugin.ts | 75 +++++++- packages/vite-plugin/package.json | 4 +- .../src/lib/vite-build-stats-plugin.spec.ts | 112 +++++++++++- .../src/lib/vite-build-stats-plugin.ts | 165 +++++++++++++++-- pnpm-lock.yaml | 2 +- 30 files changed, 2160 insertions(+), 87 deletions(-) create mode 100644 .changeset/whole-dev-cycle.md create mode 100644 examples/command.json create mode 100644 packages/common/src/hooks/postinstall.ts create mode 100644 packages/common/src/hooks/preinstall.ts create mode 100644 packages/common/src/lib/debug.ts create mode 100644 packages/common/src/lib/git.spec.ts create mode 100644 packages/common/src/lib/git.ts create mode 100644 packages/common/src/lib/install.spec.ts create mode 100644 packages/common/src/lib/install.ts create mode 100644 packages/common/src/lib/npm-timing.ts create mode 100644 packages/common/src/lib/session.spec.ts create mode 100644 packages/common/src/lib/session.ts create mode 100644 packages/common/src/lib/signals.ts create mode 100644 packages/common/src/lib/spool.spec.ts create mode 100644 packages/common/src/lib/spool.ts create mode 100644 packages/common/vite.config.ts diff --git a/.changeset/whole-dev-cycle.md b/.changeset/whole-dev-cycle.md new file mode 100644 index 0000000..33a3110 --- /dev/null +++ b/.changeset/whole-dev-cycle.md @@ -0,0 +1,15 @@ +--- +'agoda-devfeedback-common': minor +'agoda-devfeedback-vite2': minor +'agoda-devfeedback-rsbuild': minor +--- + +Extend devfeedback from single compilations to the whole local dev cycle. + +- New `type: "command"` event with an `install`, `devserver` or `clientready` phase, posted to `COMMAND_ENDPOINT` (default `http://compilation-metrics/command`). Dev server ready time was previously never measured, because `closeBundle` does not fire in dev. +- Every event now carries a `sessionId`, so install → dev server ready → first HMR correlate into one timeline. Purely additive; existing payloads are unchanged. +- Install capture for npm, yarn and pnpm. Works with no repo change; a `preinstall`/`postinstall` pair in the consuming repo upgrades it to an exact span with a trustworthy `coldInstall` flag. Install events are spooled locally and delivered by the next dev server or build, so an install never waits on the network. +- Aborted runs are recorded: Ctrl-C produces a `devserver` event with `signal` set, without changing what Ctrl-C does. +- Rspack and Rsbuild events now post to `RSPACK_ENDPOINT` (`/rspack`) as the README always documented, instead of the webpack endpoint. +- Off the critical path: 1500 ms POST timeout, git metadata cached until the repo actually changes instead of three `git` spawns per HMR event, `stats.toJson()` no longer serializes the whole compilation on every Rsbuild rebuild, and startup chatter moved behind `DEVFEEDBACK_DEBUG`. +- Widened the Vite peer range to `>=4.0.0` (`rollup >=3.0.0`). diff --git a/README.md b/README.md index 8cf9419..9675d20 100644 --- a/README.md +++ b/README.md @@ -5,8 +5,9 @@ Welcome to agoda-devfeedback, the JavaScript/TypeScript package collection that' ## Build Time (Compilation Time): Because Life's Too Short for Slow Builds This collection supports collecting build time (compilation time) metrics across multiple bundlers: + - Webpack (4.x or 5.x) -- Vite (4.x) +- Vite (4.x and up, including 6.x and Rolldown-based builds) - Rspack/Rsbuild (1.x) It's like a stopwatch for your builds, but cooler, and now with more bundlers! 🎮 @@ -15,11 +16,14 @@ It's like a stopwatch for your builds, but cooler, and now with more bundlers! The data is sent to the following default endpoints (customizable via environment variables): -| Bundler | Default | Environment Variable Override | Post Data Example -| --- | --- | --- | --- | -| WebPack | "" | WEBPACK_ENDPOINT | [click here](examples/webpack.json) | -| Vite | "" | VITE_ENDPOINT | [click here](examples/vite.json) | -| Rspack | "" | RSPACK_ENDPOINT | [click here](examples/rspack.json) | +| Bundler | Default | Environment Variable Override | Post Data Example | +| ----------------------------- | -------------------------------------- | ----------------------------- | ----------------------------------- | +| WebPack | "" | WEBPACK_ENDPOINT | [click here](examples/webpack.json) | +| Vite | "" | VITE_ENDPOINT | [click here](examples/vite.json) | +| Rspack | "" | RSPACK_ENDPOINT | [click here](examples/rspack.json) | +| Lifecycle (`type: "command"`) | "" | COMMAND_ENDPOINT | [click here](examples/command.json) | + +> **Heads up:** Rspack and Rsbuild events used to be posted to the _webpack_ endpoint despite the table above. They now go to `/rspack` as documented. If your dashboards were reading them off the webpack endpoint, point them at `/rspack` (or set `RSPACK_ENDPOINT` back to the webpack URL during the transition). ### Basic Usage: Easy as Pie (Mmm... pie 🥧) @@ -106,6 +110,85 @@ Want to track bootstrap chunk sizes? We've got you covered! Pass a size limit (i viteBuildStatsPlugin('vite-build-extraordinaire', 1000); // 1 mega byte ``` +## The Whole Dev Cycle, Not Just The Compile + +A compile time is one number out of the several a developer actually waits through. Between `git pull` and a working app there is an install, a dev server start, and a browser that has to finish booting. Vite and Rspack/Rsbuild now report all of them. + +These arrive as a new event type, `type: "command"`, on the `COMMAND_ENDPOINT`: + +| `phase` | What it measures | Emitted by | +| ------------- | ---------------------------------------------------------------------------------------------------------------------------------- | ------------------------------- | +| `install` | The package manager run, plus cold/warm and whether the lockfile changed | install hooks (npm, yarn, pnpm) | +| `devserver` | Time until the dev server is listening — the number that was previously never measured, because `closeBundle` does not fire in dev | Vite, Rsbuild, Rspack watch | +| `clientready` | Time until the app is usable in the browser, with DOMContentLoaded and first contentful paint | Vite, Rsbuild | + +Aborted runs count too: Ctrl-C on a dev server produces a `devserver` event with `success: false` and `signal: "SIGINT"`. A developer who gave up waiting is the most interesting data point on the chart. + +### Session correlation + +Every event — including the existing `webpack`, `vite`, `vitehmr`, `rspack` and `rsbuild` payloads — now carries a `sessionId`, so install → dev server ready → first HMR stitch into one timeline. It is purely additive; nothing that existed changed shape. + +The session id is resolved with zero setup: a small state file under `node_modules/.cache/devfeedback` (or a tmpdir, before `node_modules` exists) that rolls over after four idle hours. If you want exact session boundaries, set one yourself and it wins: + +```bash +export DEVFEEDBACK_SESSION_ID=$(uuidgen) +``` + +### Install timing + +Two tiers, and the first one needs nothing from you. + +**Default — no repo change.** `agoda-devfeedback-common` runs its own `postinstall` hook, which infers the install duration from the package manager's process start time. The span ends when our package is linked rather than when the whole install finishes, so it undercounts a little. + +**Exact — two lines in the consuming repo.** Add both hooks and you get the true install span, plus a trustworthy cold/warm flag on a fresh clone: + +```json +{ + "scripts": { + "preinstall": "node -e \"try{require('agoda-devfeedback-common/hooks/preinstall')}catch(e){}\"", + "postinstall": "node -e \"try{require('agoda-devfeedback-common/hooks/postinstall')}catch(e){}\"" + }, + "devDependencies": { + "agoda-devfeedback-common": "^2.0.0" + } +} +``` + +Add `agoda-devfeedback-common` as a direct devDependency for this tier — under pnpm a transitive dependency is not resolvable from the repo root. When these hooks are present the bundled one stands down, so you get one event, not two. On a genuinely cold clone the `preinstall` file does not exist yet, the `try/catch` swallows it, and the bundled hook falls back to process start time — cold clones are still measured, just less precisely. + +Known gaps, so nobody is surprised: + +- Install events are **spooled, not sent**. An install must never wait on the network, so events are written to a small local NDJSON file and delivered by the next dev server or build start. `spooledAt` tells you the delivery was deferred. Nobody watches an install dashboard in real time. +- `--ignore-scripts` skips everything here. +- **pnpm blocks dependency lifecycle scripts by default.** Allow it once during dev machine bootstrap, in `~/.config/pnpm/config.yaml`, so repos stay untouched: + ```yaml + allowBuilds: + agoda-devfeedback-common: true + ``` + (pnpm 10 and earlier call this `onlyBuiltDependencies`.) +- npm only: with `timing=true` in `.npmrc`, npm's own per-phase timers are scraped from `~/.npm/_logs/*-timing.json` and attached as `npmTimers`. That is where you find out a Playwright browser download or a `node-gyp` rebuild is what actually costs you three minutes. + +### Rollout tiers + +| Tier | Repo change | What you get | +| ------------------------------------------------------------------------------- | -------------------------------------------- | ------------------------------------------- | +| Shared preset (e.g. `@agoda/vite-config` re-exporting `viteBuildStatsPlugin()`) | none, just a version bump | everything below except exact install spans | +| Direct install | one plugin line | same | +| Exact install timing | two `scripts` lines + a direct devDependency | true install span and cold-clone accuracy | +| npm repos, opt-in | one `.npmrc` line (`timing=true`) | per-phase and per-package install breakdown | +| Advanced | `DEVFEEDBACK_SESSION_ID` in your shell | precise session boundaries | + +### Staying off the critical path + +Telemetry that slows people down gets deleted from configs, so: + +- Every POST has a 1500 ms timeout. Off-VPN, nothing hangs. +- Git metadata is read once and cached until the repository actually changes, instead of spawning three `git` processes per HMR event. +- The session id is resolved once per process; the HMR path performs no synchronous filesystem writes and no process spawns. +- Signal handlers write synchronously and then get out of the way, so Ctrl-C behaves exactly as it would without the plugin. +- The spool is capped at 256 KB and events older than a week are dropped rather than accumulated. +- Startup chatter is behind `DEVFEEDBACK_DEBUG=1`. At the default log level the lifecycle events print nothing at all. + ## The F5 Experience: Because Waiting is So Last Year What is the F5 Experience? Have a read [here](https://beerandserversdontmix.com/2024/08/15/an-introduction-to-the-f5-experience/) @@ -125,4 +208,4 @@ Remember, in the world of agoda-devfeedback, there are no stupid questions, only Remember, in JavaScript development, there are only two types of projects: those that are measuring their build times, and those that are still waiting for their builds to finish. With agoda-devfeedback, you'll always know exactly how long you're waiting. (Spoiler alert: with our help, it won't be long!) -Happy coding, and may your builds be ever faster! 🚀 \ No newline at end of file +Happy coding, and may your builds be ever faster! 🚀 diff --git a/examples/command.json b/examples/command.json new file mode 100644 index 0000000..b0794ac --- /dev/null +++ b/examples/command.json @@ -0,0 +1,169 @@ +{ + "install": { + "id": "9f1c2b40-1a2e-11f0-9c3a-0242ac120002", + "sessionId": "3c9f1e64-6b1c-4a0a-9e2f-8f0f7a5d1b21", + "userName": "jane.doe", + "cpuCount": 8, + "hostname": "jane-laptop", + "platform": "Darwin", + "os": "23.5.0", + "timeTaken": 48213, + "branch": "feature/checkout-redesign", + "projectName": "my-vite-project", + "repository": "https://github.com/example/my-vite-project", + "repositoryName": "my-vite-project", + "timestamp": 1785900000000, + "builtAt": "2026-08-05T03:20:00.000Z", + "totalMemory": 34359738368, + "cpuModels": ["Apple M3 Pro"], + "cpuSpeed": [0], + "nodeVersion": "v22.14.0", + "v8Version": "12.4.254.21-node.35", + "commitSha": "2b8f1c9a6e5d4c3b2a1908f7e6d5c4b3a2918070", + "customIdentifier": "install", + "type": "command", + "phase": "install", + "command": "pnpm/9.0.0 npm/? node/v22.14.0 darwin arm64", + "exitCode": 0, + "success": true, + "packageManager": "pnpm", + "packageManagerVersion": "9.0.0", + "coldInstall": true, + "lockfileChanged": true, + "measurementSource": "preinstall", + "spooledAt": 1785900000123 + }, + + "devserver": { + "id": "a1d3e550-1a2e-11f0-9c3a-0242ac120002", + "sessionId": "3c9f1e64-6b1c-4a0a-9e2f-8f0f7a5d1b21", + "userName": "jane.doe", + "cpuCount": 8, + "hostname": "jane-laptop", + "platform": "Darwin", + "os": "23.5.0", + "timeTaken": 4120, + "branch": "feature/checkout-redesign", + "projectName": "my-vite-project", + "repository": "https://github.com/example/my-vite-project", + "repositoryName": "my-vite-project", + "timestamp": 1785900060000, + "builtAt": "2026-08-05T03:21:00.000Z", + "totalMemory": 34359738368, + "cpuModels": ["Apple M3 Pro"], + "cpuSpeed": [0], + "nodeVersion": "v22.14.0", + "v8Version": "12.4.254.21-node.35", + "commitSha": "2b8f1c9a6e5d4c3b2a1908f7e6d5c4b3a2918070", + "customIdentifier": "dev", + "type": "command", + "phase": "devserver", + "command": "vite dev", + "exitCode": 0, + "success": true, + "prebundled": true + }, + + "devserverAborted": { + "id": "b7a4f660-1a2e-11f0-9c3a-0242ac120002", + "sessionId": "3c9f1e64-6b1c-4a0a-9e2f-8f0f7a5d1b21", + "userName": "jane.doe", + "cpuCount": 8, + "hostname": "jane-laptop", + "platform": "Darwin", + "os": "23.5.0", + "timeTaken": 91340, + "branch": "feature/checkout-redesign", + "projectName": "my-vite-project", + "repository": "https://github.com/example/my-vite-project", + "repositoryName": "my-vite-project", + "timestamp": 1785900160000, + "builtAt": "2026-08-05T03:22:40.000Z", + "totalMemory": 34359738368, + "cpuModels": ["Apple M3 Pro"], + "cpuSpeed": [0], + "nodeVersion": "v22.14.0", + "v8Version": "12.4.254.21-node.35", + "commitSha": "2b8f1c9a6e5d4c3b2a1908f7e6d5c4b3a2918070", + "customIdentifier": "dev", + "type": "command", + "phase": "devserver", + "command": "vite dev", + "exitCode": 130, + "success": false, + "signal": "SIGINT", + "spooledAt": 1785900160500 + }, + + "clientready": { + "id": "c3b5a770-1a2e-11f0-9c3a-0242ac120002", + "sessionId": "3c9f1e64-6b1c-4a0a-9e2f-8f0f7a5d1b21", + "userName": "jane.doe", + "cpuCount": 8, + "hostname": "jane-laptop", + "platform": "Darwin", + "os": "23.5.0", + "timeTaken": 6890, + "branch": "feature/checkout-redesign", + "projectName": "my-vite-project", + "repository": "https://github.com/example/my-vite-project", + "repositoryName": "my-vite-project", + "timestamp": 1785900066000, + "builtAt": "2026-08-05T03:21:06.000Z", + "totalMemory": 34359738368, + "cpuModels": ["Apple M3 Pro"], + "cpuSpeed": [0], + "nodeVersion": "v22.14.0", + "v8Version": "12.4.254.21-node.35", + "commitSha": "2b8f1c9a6e5d4c3b2a1908f7e6d5c4b3a2918070", + "customIdentifier": "dev", + "type": "command", + "phase": "clientready", + "command": "vite dev", + "exitCode": 0, + "success": true, + "domContentLoadedMs": 1840, + "firstContentfulPaintMs": 2210 + }, + + "installWithNpmTimers": { + "id": "d9c6b880-1a2e-11f0-9c3a-0242ac120002", + "sessionId": "3c9f1e64-6b1c-4a0a-9e2f-8f0f7a5d1b21", + "userName": "jane.doe", + "cpuCount": 8, + "hostname": "jane-laptop", + "platform": "Darwin", + "os": "23.5.0", + "timeTaken": 51204, + "branch": "feature/checkout-redesign", + "projectName": "my-vite-project", + "repository": "https://github.com/example/my-vite-project", + "repositoryName": "my-vite-project", + "timestamp": 1785900070000, + "builtAt": "2026-08-05T03:21:10.000Z", + "totalMemory": 34359738368, + "cpuModels": ["Apple M3 Pro"], + "cpuSpeed": [0], + "nodeVersion": "v22.14.0", + "v8Version": "12.4.254.21-node.35", + "commitSha": "2b8f1c9a6e5d4c3b2a1908f7e6d5c4b3a2918070", + "customIdentifier": "install", + "type": "command", + "phase": "install", + "command": "npm install", + "exitCode": 0, + "success": true, + "packageManager": "npm", + "packageManagerVersion": "10.9.2", + "measurementSource": "npm-timing", + "npmTimers": { + "npm": 51204, + "idealTree": 8120, + "reify": 39880, + "build:run:install:node_modules/playwright": 21430, + "build:run:postinstall:node_modules/husky": 310, + "audit": 1220 + }, + "spooledAt": 1785900065000 + } +} diff --git a/packages/common/package.json b/packages/common/package.json index 94cf2b2..a700d1e 100644 --- a/packages/common/package.json +++ b/packages/common/package.json @@ -11,7 +11,9 @@ "types": "./dist/index.d.ts", "import": "./dist/index.js", "require": "./dist/index.cjs" - } + }, + "./hooks/preinstall": "./dist/hooks/preinstall.cjs", + "./hooks/postinstall": "./dist/hooks/postinstall.cjs" }, "files": [ "dist", @@ -20,7 +22,9 @@ "scripts": { "build": "tsup", "dev": "tsup --watch", - "check-types": "tsc --noEmit" + "check-types": "tsc --noEmit", + "test": "vitest", + "postinstall": "node ./dist/hooks/postinstall.cjs --self || exit 0" }, "dependencies": { "axios": "1.8.4", diff --git a/packages/common/src/hooks/postinstall.ts b/packages/common/src/hooks/postinstall.ts new file mode 100644 index 0000000..954c080 --- /dev/null +++ b/packages/common/src/hooks/postinstall.ts @@ -0,0 +1,95 @@ +/** + * Install capture, in two roles decided by `--self`: + * + * - bundled (`--self`): runs as this package's own postinstall, so every repo that + * depends on devfeedback gets install timing with no package.json change. Duration + * is inferred from the package manager's process start time, and the span ends when + * our package is linked rather than when the install finishes. + * + * - root (no flag): runs as the consuming repo's postinstall, paired with the + * preinstall hook. Exact span, exact cold/warm flag. Whenever the preinstall marker + * is present the bundled role stands down so only one event is produced. + * + * The event is spooled, never sent: an install must never wait on the network, least of + * all for an off-VPN developer. + */ +import { getCommonMetadata } from '../lib/common'; +import { + detectPackageManager, + installRoot, + lockfileHash, + parentStartedAt, +} from '../lib/install'; +import { getSessionId, readState, writeState } from '../lib/session'; +import { spoolCommandData } from '../lib/spool'; +import type { CommandBuildData } from '../lib/types'; + +/** a marker older than this belongs to an install that never finished */ +const MARKER_TTL_MS = 60 * 60 * 1000; + +const main = () => { + const selfMode = process.argv.includes('--self'); + const root = installRoot(); + // read before priming the session: getSessionId writes state, and "no state at all" + // is what tells us this was a cold install when there is no preinstall marker + const prev = readState(root); + // prime the session memo from the repo root before anything reads it via + // getCommonMetadata — our own cwd is inside node_modules and would resolve elsewhere + const sessionId = getSessionId(root); + const now = Date.now(); + + const marker = + prev?.installStartedAt !== undefined && now - prev.installStartedAt < MARKER_TTL_MS + ? prev + : undefined; + + // the repo has its own hooks: let the root postinstall report the full install + if (selfMode && marker?.expectRootPostinstall) return; + + const startedAt = marker?.installStartedAt ?? parentStartedAt(process.ppid, prev, root); + if (!startedAt) return; + + const hash = lockfileHash(root); + const before = marker?.preInstallLockfileHash ?? prev?.lockfileHash; + const { packageManager, packageManagerVersion, userAgent } = detectPackageManager(); + + const event: CommandBuildData = { + ...getCommonMetadata(now - startedAt, 'install'), + sessionId, + type: 'command', + phase: 'install', + command: userAgent || 'install', + exitCode: 0, + success: true, + packageManager, + packageManagerVersion, + coldInstall: marker?.installWasCold ?? prev === undefined, + lockfileChanged: Boolean(before && hash !== before), + measurementSource: marker ? 'preinstall' : 'postinstall', + }; + + spoolCommandData(event, root); + + const latest = readState(root); + writeState( + { + ...(latest ?? { sessionId }), + sessionId: latest?.sessionId ?? sessionId, + lastSeenAt: now, + lockfileHash: hash, + installStartedAt: undefined, + installWasCold: undefined, + preInstallLockfileHash: undefined, + expectRootPostinstall: undefined, + }, + root, + ); +}; + +// MUST NOT fail or slow the install under any circumstance +try { + main(); +} catch { + /* ignore */ +} +process.exitCode = 0; diff --git a/packages/common/src/hooks/preinstall.ts b/packages/common/src/hooks/preinstall.ts new file mode 100644 index 0000000..a20c7fc --- /dev/null +++ b/packages/common/src/hooks/preinstall.ts @@ -0,0 +1,46 @@ +/** + * Root `preinstall` hook (the "Option A" install capture route). + * + * "preinstall": "node ./node_modules/agoda-devfeedback-common/dist/hooks/preinstall.js || exit 0" + * + * This is the only way to get an exact install start time and a trustworthy cold/warm + * flag, because it is the only code that runs before node_modules exists. It writes a + * marker; the matching root postinstall hook turns that marker into an event. + * + * On a genuinely cold clone this file has not been installed yet, so the script fails + * and `|| exit 0` swallows it — the bundled postinstall hook then falls back to the + * package manager's process start time. Cold clones are still measured, just less + * precisely. + */ +import { existsSync } from 'node:fs'; +import { join } from 'node:path'; +import { installRoot, lockfileHash } from '../lib/install'; +import { getSessionId, readState, writeState } from '../lib/session'; + +const main = () => { + const root = installRoot(); + const sessionId = getSessionId(root); + const prev = readState(root); + const now = Date.now(); + + writeState( + { + ...(prev ?? {}), + sessionId, + lastSeenAt: now, + installStartedAt: now, + installWasCold: !existsSync(join(root, 'node_modules')), + preInstallLockfileHash: lockfileHash(root), + expectRootPostinstall: true, + }, + root, + ); +}; + +// MUST NOT fail or slow the install under any circumstance +try { + main(); +} catch { + /* ignore */ +} +process.exitCode = 0; diff --git a/packages/common/src/index.ts b/packages/common/src/index.ts index e1a9c67..99bd250 100644 --- a/packages/common/src/index.ts +++ b/packages/common/src/index.ts @@ -1,12 +1,26 @@ +export { getCommonMetadata, sendBuildData, sendCommandData } from './lib/common'; +export { getSessionId, readState, writeState, stateDir } from './lib/session'; +export { spoolCommandData, flushSpool } from './lib/spool'; +export { onAbort } from './lib/signals'; +export { getGitInfo, invalidateGitCache } from './lib/git'; +export { isDebug, debugLog, debugWarn, debugError } from './lib/debug'; export { - getCommonMetadata, - sendBuildData -} from './lib/common'; + detectPackageManager, + lockfileHash, + installRoot, + parentStartedAt, +} from './lib/install'; +export { collectNpmTimings } from './lib/npm-timing'; +export type { SessionState } from './lib/session'; +export type { GitInfo } from './lib/git'; export type { - CommonMetadata, - ViteBuildData, - RspackBuildData, - WebpackBuildData, - DevFeedbackEvent, - ViteBundleStats + CommonMetadata, + CommandBuildData, + CommandPhase, + PackageManager, + ViteBuildData, + RspackBuildData, + WebpackBuildData, + DevFeedbackEvent, + ViteBundleStats, } from './lib/types'; diff --git a/packages/common/src/lib/common.ts b/packages/common/src/lib/common.ts index 6181a61..420c0fa 100644 --- a/packages/common/src/lib/common.ts +++ b/packages/common/src/lib/common.ts @@ -1,4 +1,5 @@ import type { + CommandBuildData, CommonMetadata, ViteBuildData, RspackBuildData, @@ -7,56 +8,52 @@ import type { import { v1 as uuidv1 } from 'uuid'; import os from 'node:os'; import fs from 'node:fs'; -import { spawnSync } from 'node:child_process'; import safelyTry from './safely-retry'; import axios from 'axios'; +import { getGitInfo } from './git'; +import { getSessionId } from './session'; const UNKNOWN_VALUE = ''; -const runGitCommand = (args: string[]): string | undefined => { - const { data: result } = safelyTry(() => - spawnSync('git', args).stdout.toString().trim(), - ); - return result; -}; +/** + * Off-VPN a POST with no timeout hangs until the OS TCP timeout, on the critical + * path of whatever the developer is actually doing. Nothing we send is worth a wait. + */ +const SEND_TIMEOUT_MS = 1500; export const getCommonMetadata = ( timeTaken: number, customIdentifier: string = process.env.npm_lifecycle_event ?? UNKNOWN_VALUE, ): CommonMetadata => { - const repoUrl = runGitCommand(['config', '--get', 'remote.origin.url']); - let repoName = repoUrl - ? repoUrl.substring(repoUrl.lastIndexOf('/') + 1) - : UNKNOWN_VALUE; - repoName = repoName.endsWith('.git') - ? repoName.substring(0, repoName.lastIndexOf('.')) - : repoName; + const git = getGitInfo(); const { data: gitUserName } = safelyTry( () => process.env['GITLAB_USER_LOGIN'] ?? process.env['GITHUB_ACTOR'], ); const { data: osUsername } = safelyTry(() => os.userInfo().username); + const cpus = os.cpus(); return { id: uuidv1(), + sessionId: getSessionId(), userName: (gitUserName ? gitUserName : osUsername) ?? UNKNOWN_VALUE, - cpuCount: os.cpus().length, + cpuCount: cpus.length, hostname: os.hostname(), platform: os.type(), os: os.release(), timeTaken: timeTaken, - branch: runGitCommand(['rev-parse', '--abbrev-ref', 'HEAD']) ?? UNKNOWN_VALUE, - projectName: repoName, - repository: repoUrl ?? UNKNOWN_VALUE, - repositoryName: repoName, + branch: git.branch ?? UNKNOWN_VALUE, + projectName: git.repositoryName ?? UNKNOWN_VALUE, + repository: git.repository ?? UNKNOWN_VALUE, + repositoryName: git.repositoryName ?? UNKNOWN_VALUE, timestamp: Date.now(), builtAt: new Date().toISOString(), totalMemory: os.totalmem(), - cpuModels: os.cpus().map((cpu) => cpu.model), - cpuSpeed: os.cpus().map((cpu) => cpu.speed), + cpuModels: cpus.map((cpu) => cpu.model), + cpuSpeed: cpus.map((cpu) => cpu.speed), nodeVersion: process.version, v8Version: process.versions.v8, - commitSha: runGitCommand(['rev-parse', 'HEAD']) ?? UNKNOWN_VALUE, + commitSha: git.commitSha ?? UNKNOWN_VALUE, customIdentifier: customIdentifier, }; }; @@ -66,17 +63,25 @@ const getEndpointFromType = (type: string) => { webpack: process.env.WEBPACK_ENDPOINT || 'http://compilation-metrics/webpack', vite: process.env.VITE_ENDPOINT || 'http://compilation-metrics/vite', vitehmr: process.env.VITE_ENDPOINT || 'http://compilation-metrics/vite', - rsbuild: process.env.RSPACK_ENDPOINT || 'http://compilation-metrics/webpack', - rspack: process.env.RSPACK_ENDPOINT || 'http://compilation-metrics/webpack', + rsbuild: process.env.RSPACK_ENDPOINT || 'http://compilation-metrics/rspack', + rspack: process.env.RSPACK_ENDPOINT || 'http://compilation-metrics/rspack', + command: process.env.COMMAND_ENDPOINT || 'http://compilation-metrics/command', }[type]; }; const LOG_FILE = 'devfeedback.log'; const sendData = async (endpoint: string, metaData: CommonMetadata): Promise => { - const { error } = await safelyTry(() => axios.post(endpoint, metaData)); + const { error } = await safelyTry(() => + axios.post(endpoint, metaData, { timeout: SEND_TIMEOUT_MS }), + ); if (error) { - fs.writeFileSync(LOG_FILE, JSON.stringify(error, Object.getOwnPropertyNames(error))); + safelyTry(() => + fs.writeFileSync( + LOG_FILE, + JSON.stringify(error, Object.getOwnPropertyNames(error)), + ), + ); return false; } return true; @@ -108,3 +113,14 @@ export const sendBuildData = async ( `Your build stats has successfully been sent to ${endpoint} for ${buildStats.type}.`, ); }; + +/** + * Lifecycle events are emitted from places a developer is not asking for output — + * install hooks, dev server startup, signal handlers — so this path prints nothing. + * Failures land in devfeedback.log like everything else. + */ +export const sendCommandData = async (data: CommandBuildData): Promise => { + const endpoint = getEndpointFromType(data.type); + if (!endpoint) return; + await sendData(endpoint, data); +}; diff --git a/packages/common/src/lib/debug.ts b/packages/common/src/lib/debug.ts new file mode 100644 index 0000000..1496723 --- /dev/null +++ b/packages/common/src/lib/debug.ts @@ -0,0 +1,21 @@ +/** + * Console output from a telemetry plugin is the fastest route to being deleted + * from someone's config. Everything informational goes behind DEVFEEDBACK_DEBUG. + */ +export const isDebug = (): boolean => { + const value = process.env.DEVFEEDBACK_DEBUG; + return value !== undefined && value !== '' && value !== '0' && value !== 'false'; +}; + +/* eslint-disable @typescript-eslint/no-explicit-any */ +export const debugLog = (...args: any[]): void => { + if (isDebug()) console.log(...args); +}; + +export const debugWarn = (...args: any[]): void => { + if (isDebug()) console.warn(...args); +}; + +export const debugError = (...args: any[]): void => { + if (isDebug()) console.error(...args); +}; diff --git a/packages/common/src/lib/git.spec.ts b/packages/common/src/lib/git.spec.ts new file mode 100644 index 0000000..a6409df --- /dev/null +++ b/packages/common/src/lib/git.spec.ts @@ -0,0 +1,72 @@ +import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest'; +import { execFileSync } from 'node:child_process'; +import { mkdtempSync, rmSync, writeFileSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; + +import { getGitInfo, invalidateGitCache } from './git'; + +describe('getGitInfo', () => { + let repo: string; + + beforeEach(() => { + invalidateGitCache(); + repo = mkdtempSync(join(tmpdir(), 'devfeedback-git-')); + execFileSync('git', ['init', '--initial-branch=main'], { cwd: repo }); + execFileSync('git', ['config', 'user.email', 'test@example.com'], { cwd: repo }); + execFileSync('git', ['config', 'user.name', 'Test'], { cwd: repo }); + execFileSync('git', ['config', 'remote.origin.url', 'git@host:team/my-repo.git'], { + cwd: repo, + }); + writeFileSync(join(repo, 'a.txt'), 'a'); + execFileSync('git', ['add', '.'], { cwd: repo }); + execFileSync('git', ['commit', '-m', 'first'], { cwd: repo }); + }); + + afterEach(() => { + rmSync(repo, { recursive: true, force: true }); + invalidateGitCache(); + vi.restoreAllMocks(); + }); + + it('reports branch, sha and repository name', () => { + const info = getGitInfo(repo); + expect(info.branch).toBe('main'); + expect(info.commitSha).toMatch(/^[0-9a-f]{40}$/); + expect(info.repository).toBe('git@host:team/my-repo.git'); + expect(info.repositoryName).toBe('my-repo'); + }); + + it('serves repeated calls from cache rather than re-running git', () => { + // this is the HMR hot path — an identical object reference means nothing re-ran + const first = getGitInfo(repo); + for (let i = 0; i < 20; i++) { + expect(getGitInfo(repo)).toBe(first); + } + }); + + it('picks up a new commit', () => { + const before = getGitInfo(repo).commitSha; + writeFileSync(join(repo, 'b.txt'), 'b'); + execFileSync('git', ['add', '.'], { cwd: repo }); + execFileSync('git', ['commit', '-m', 'second'], { cwd: repo }); + + expect(getGitInfo(repo).commitSha).not.toBe(before); + }); + + it('picks up a branch switch', () => { + execFileSync('git', ['checkout', '-b', 'feature/x'], { cwd: repo }); + expect(getGitInfo(repo).branch).toBe('feature/x'); + }); + + it('returns undefined fields outside a repository, without throwing', () => { + const plain = mkdtempSync(join(tmpdir(), 'devfeedback-nogit-')); + try { + const info = getGitInfo(plain); + expect(info.repository).toBeUndefined(); + expect(info.repositoryName).toBeUndefined(); + } finally { + rmSync(plain, { recursive: true, force: true }); + } + }); +}); diff --git a/packages/common/src/lib/git.ts b/packages/common/src/lib/git.ts new file mode 100644 index 0000000..3f58f53 --- /dev/null +++ b/packages/common/src/lib/git.ts @@ -0,0 +1,111 @@ +import { spawnSync } from 'node:child_process'; +import { existsSync, readFileSync, statSync } from 'node:fs'; +import { dirname, isAbsolute, join, parse } from 'node:path'; +import safelyTry from './safely-retry'; + +export interface GitInfo { + repository: string | undefined; + repositoryName: string | undefined; + branch: string | undefined; + commitSha: string | undefined; +} + +const runGitCommand = (args: string[], cwd: string): string | undefined => { + const { data: result } = safelyTry(() => + spawnSync('git', args, { cwd }).stdout.toString().trim(), + ); + return result ? result : undefined; +}; + +/** Locate the real .git directory, following the `gitdir:` pointer used by worktrees. */ +const findGitDir = (start: string): string | undefined => { + let dir = start; + const { root } = parse(start); + for (;;) { + const candidate = join(dir, '.git'); + if (existsSync(candidate)) { + try { + const stat = statSync(candidate); + if (stat.isDirectory()) return candidate; + const pointer = /^gitdir:\s*(.+)$/m.exec(readFileSync(candidate, 'utf8'))?.[1]; + if (pointer) return isAbsolute(pointer) ? pointer : join(dir, pointer); + } catch { + return undefined; + } + return undefined; + } + if (dir === root) return undefined; + const parent = dirname(dir); + if (parent === dir) return undefined; + dir = parent; + } +}; + +/** + * A cheap value that changes whenever any of the git facts we report could have + * changed: checkout, commit, fetch that rewrites packed-refs, or a remote edit. + * Three `statSync` calls beat three `git` process spawns by two orders of magnitude, + * which matters because this runs once per HMR event. + */ +const fingerprint = (gitDir: string): string => { + const parts: string[] = []; + const mtime = (p: string): string => { + try { + return String(statSync(p).mtimeMs); + } catch { + return '-'; + } + }; + + const headPath = join(gitDir, 'HEAD'); + parts.push(mtime(headPath)); + try { + const head = readFileSync(headPath, 'utf8').trim(); + const ref = /^ref:\s*(.+)$/.exec(head)?.[1]; + parts.push(ref ? mtime(join(gitDir, ref)) : head); + } catch { + parts.push('-'); + } + parts.push(mtime(join(gitDir, 'packed-refs'))); + parts.push(mtime(join(gitDir, 'config'))); + return parts.join('|'); +}; + +let cache: { cwd: string; key: string; info: GitInfo } | undefined; + +const readGitInfo = (cwd: string): GitInfo => { + const repository = runGitCommand(['config', '--get', 'remote.origin.url'], cwd); + let repositoryName = repository + ? repository.substring(repository.lastIndexOf('/') + 1) + : undefined; + repositoryName = repositoryName?.endsWith('.git') + ? repositoryName.substring(0, repositoryName.lastIndexOf('.')) + : repositoryName; + + return { + repository, + repositoryName, + branch: runGitCommand(['rev-parse', '--abbrev-ref', 'HEAD'], cwd), + commitSha: runGitCommand(['rev-parse', 'HEAD'], cwd), + }; +}; + +/** + * Git facts for `cwd`, cached for the lifetime of the process and invalidated only + * when the repository state actually changes. Never spawns `git` on a cache hit. + */ +export const getGitInfo = (cwd: string = process.cwd()): GitInfo => { + const gitDir = findGitDir(cwd); + const key = gitDir ? fingerprint(gitDir) : 'no-git'; + + if (cache && cache.cwd === cwd && cache.key === key) return cache.info; + + const info = readGitInfo(cwd); + cache = { cwd, key, info }; + return info; +}; + +/** test seam / explicit invalidation hook for consumers that watch .git themselves */ +export const invalidateGitCache = (): void => { + cache = undefined; +}; diff --git a/packages/common/src/lib/install.spec.ts b/packages/common/src/lib/install.spec.ts new file mode 100644 index 0000000..900b615 --- /dev/null +++ b/packages/common/src/lib/install.spec.ts @@ -0,0 +1,114 @@ +import { describe, it, expect, beforeEach, afterEach } from 'vitest'; +import { mkdtempSync, rmSync, writeFileSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; + +import { + detectPackageManager, + installRoot, + lockfileHash, + parentStartedAt, +} from './install'; + +describe('lockfileHash', () => { + let root: string; + + beforeEach(() => { + root = mkdtempSync(join(tmpdir(), 'devfeedback-lock-')); + }); + + afterEach(() => { + rmSync(root, { recursive: true, force: true }); + }); + + it('is undefined when the repo has no lockfile', () => { + expect(lockfileHash(root)).toBeUndefined(); + }); + + it.each(['pnpm-lock.yaml', 'package-lock.json', 'yarn.lock'])('hashes %s', (name) => { + writeFileSync(join(root, name), 'lockfile contents'); + expect(lockfileHash(root)).toBeTypeOf('string'); + }); + + it('changes when the lockfile changes', () => { + writeFileSync(join(root, 'pnpm-lock.yaml'), 'a'); + const before = lockfileHash(root); + writeFileSync(join(root, 'pnpm-lock.yaml'), 'b'); + expect(lockfileHash(root)).not.toBe(before); + }); + + it('is stable when nothing changes', () => { + writeFileSync(join(root, 'yarn.lock'), 'a'); + expect(lockfileHash(root)).toBe(lockfileHash(root)); + }); + + it('notices a change in any lockfile when several are present', () => { + writeFileSync(join(root, 'pnpm-lock.yaml'), 'a'); + writeFileSync(join(root, 'yarn.lock'), 'a'); + const before = lockfileHash(root); + writeFileSync(join(root, 'yarn.lock'), 'b'); + expect(lockfileHash(root)).not.toBe(before); + }); +}); + +describe('detectPackageManager', () => { + const original = process.env.npm_config_user_agent; + + afterEach(() => { + if (original === undefined) delete process.env.npm_config_user_agent; + else process.env.npm_config_user_agent = original; + }); + + it.each([ + ['pnpm/9.0.0 npm/? node/v20.11.0 linux x64', 'pnpm', '9.0.0'], + ['npm/10.2.4 node/v20.11.0 darwin arm64 workspaces/false', 'npm', '10.2.4'], + ['yarn/1.22.19 npm/? node/v20.11.0 linux x64', 'yarn', '1.22.19'], + ])('parses %s', (userAgent, expectedName, expectedVersion) => { + process.env.npm_config_user_agent = userAgent; + const result = detectPackageManager(); + expect(result.packageManager).toBe(expectedName); + expect(result.packageManagerVersion).toBe(expectedVersion); + }); + + it('reports no package manager for an unknown user agent', () => { + process.env.npm_config_user_agent = 'bun/1.0.0 node/v20.11.0'; + expect(detectPackageManager().packageManager).toBeUndefined(); + }); + + it('survives a missing user agent', () => { + delete process.env.npm_config_user_agent; + expect(detectPackageManager()).toMatchObject({ userAgent: '' }); + }); +}); + +describe('installRoot', () => { + const original = process.env.INIT_CWD; + + afterEach(() => { + if (original === undefined) delete process.env.INIT_CWD; + else process.env.INIT_CWD = original; + }); + + it('prefers INIT_CWD, the repo the package manager was invoked in', () => { + process.env.INIT_CWD = '/somewhere/else'; + expect(installRoot()).toBe('/somewhere/else'); + }); + + it('falls back to cwd', () => { + delete process.env.INIT_CWD; + expect(installRoot()).toBe(process.cwd()); + }); +}); + +describe('parentStartedAt', () => { + it('reads a plausible start time for our own process', () => { + const startedAt = parentStartedAt(process.pid); + if (startedAt === undefined) return; // unsupported platform: a missing duration is fine + expect(startedAt).toBeLessThanOrEqual(Date.now() + 1000); + expect(startedAt).toBeGreaterThan(Date.now() - 24 * 60 * 60 * 1000); + }); + + it('returns undefined rather than throwing for a pid that does not exist', () => { + expect(() => parentStartedAt(2 ** 30)).not.toThrow(); + }); +}); diff --git a/packages/common/src/lib/install.ts b/packages/common/src/lib/install.ts new file mode 100644 index 0000000..da1782e --- /dev/null +++ b/packages/common/src/lib/install.ts @@ -0,0 +1,155 @@ +import { execFileSync } from 'node:child_process'; +import { createHash } from 'node:crypto'; +import { existsSync, readFileSync } from 'node:fs'; +import { join } from 'node:path'; +import { getSessionId, writeState, type SessionState } from './session'; +import type { PackageManager } from './types'; + +/** npm, yarn and pnpm are all in scope, so every lockfile shape counts. */ +export const LOCKFILES: Record = { + 'pnpm-lock.yaml': 'pnpm', + 'package-lock.json': 'npm', + 'npm-shrinkwrap.json': 'npm', + 'yarn.lock': 'yarn', +}; + +/** + * Hash of whichever lockfile this repo uses. Repos with more than one (a yarn.lock + * left behind after a pnpm migration, say) hash all of them so either changing counts. + */ +export const lockfileHash = (root: string): string | undefined => { + const hash = createHash('sha1'); + let found = false; + for (const name of Object.keys(LOCKFILES)) { + const p = join(root, name); + if (!existsSync(p)) continue; + try { + hash.update(name).update(readFileSync(p)); + found = true; + } catch { + /* unreadable lockfile: treat as absent */ + } + } + return found ? hash.digest('hex').slice(0, 16) : undefined; +}; + +/** + * Every supported package manager sets npm_config_user_agent, e.g. + * "pnpm/9.0.0 npm/? node/v20.11.0 linux x64". + */ +export const detectPackageManager = (): { + packageManager?: PackageManager; + packageManagerVersion?: string; + userAgent: string; +} => { + const userAgent = process.env.npm_config_user_agent ?? ''; + const [name, version] = userAgent.split(' ')[0]?.split('/') ?? []; + const known: PackageManager[] = ['npm', 'yarn', 'pnpm']; + return { + packageManager: known.includes(name as PackageManager) + ? (name as PackageManager) + : undefined, + packageManagerVersion: version, + userAgent, + }; +}; + +/** + * A missing install duration is fine; a slow install is not. Every platform gets the + * same tight budget. + */ +const BUDGET_MS = 500; + +const winStartedAt = ( + pid: number, + prev?: SessionState, + root?: string, +): number | undefined => { + const method = prev?.winProcTimeMethod; + if (method === 'none') return undefined; // this machine has already told us it can't + + const remember = (m: SessionState['winProcTimeMethod']) => + writeState( + { + ...(prev ?? { sessionId: getSessionId(root), lastSeenAt: Date.now() }), + winProcTimeMethod: m, + }, + root, + ); + + // wmic is deprecated and absent from Windows 11 24H2 / Server 2025, but when it is + // missing the spawn fails with ENOENT in single-digit milliseconds — far cheaper + // than PowerShell's CLR startup on the machines that still have it. + if (method !== 'powershell') { + try { + const out = execFileSync( + 'wmic', + ['process', 'where', `processid=${pid}`, 'get', 'creationdate', '/value'], + { encoding: 'utf8', timeout: BUDGET_MS, windowsHide: true }, + ); + const m = /CreationDate=(\d{14})/.exec(out); + if (m?.[1]) { + const s = m[1]; + remember('wmic'); + return Date.parse( + `${s.slice(0, 4)}-${s.slice(4, 6)}-${s.slice(6, 8)}T${s.slice(8, 10)}:${s.slice(10, 12)}:${s.slice(12, 14)}`, + ); + } + } catch { + /* removed in 24H2+, or blocked — fall through */ + } + } + + if (method === 'wmic') return undefined; // wmic worked before and failed now: don't escalate + + try { + const out = execFileSync( + 'powershell', + [ + '-NoProfile', + '-NonInteractive', + '-Command', + `(Get-Process -Id ${pid}).StartTime.ToFileTimeUtc()`, + ], + { encoding: 'utf8', timeout: BUDGET_MS, windowsHide: true }, + ); + remember('powershell'); + return Number(BigInt(out.trim()) / 10000n) - 11644473600000; // FILETIME → epoch ms + } catch { + remember('none'); // pay this once per machine, never again + return undefined; + } +}; + +/** wall-clock start of the package manager process that invoked us */ +export const parentStartedAt = ( + pid: number, + prev?: SessionState, + root?: string, +): number | undefined => { + try { + if (process.platform === 'linux') { + const stat = readFileSync(`/proc/${pid}/stat`, 'utf8'); + const ticks = Number(stat.slice(stat.lastIndexOf(')') + 2).split(' ')[19]); + const btime = Number( + /btime (\d+)/.exec(readFileSync('/proc/stat', 'utf8'))?.[1] ?? 0, + ); + if (!btime || !Number.isFinite(ticks)) return undefined; + return (btime + ticks / 100) * 1000; // USER_HZ is 100 on mainstream builds + } + if (process.platform === 'darwin') { + const out = execFileSync('ps', ['-o', 'lstart=', '-p', String(pid)], { + encoding: 'utf8', + timeout: BUDGET_MS, + }); + const parsed = new Date(out.trim()).getTime(); + return Number.isFinite(parsed) ? parsed : undefined; + } + return winStartedAt(pid, prev, root); + } catch { + return undefined; + } +}; + +/** The repo the package manager was invoked in, not the package we happen to live in. */ +export const installRoot = (): string => process.env.INIT_CWD ?? process.cwd(); diff --git a/packages/common/src/lib/npm-timing.ts b/packages/common/src/lib/npm-timing.ts new file mode 100644 index 0000000..cd91ade --- /dev/null +++ b/packages/common/src/lib/npm-timing.ts @@ -0,0 +1,120 @@ +import { readdirSync, readFileSync, statSync } from 'node:fs'; +import { homedir } from 'node:os'; +import { join } from 'node:path'; +import { getCommonMetadata, sendCommandData } from './common'; +import { getSessionId, readState, writeState } from './session'; +import type { CommandBuildData } from './types'; + +/** + * `npm install --timing` (or `timing=true` in .npmrc) writes per-phase timers to + * ~/.npm/_logs/*-timing.json. The per-script timers are the most actionable install + * data we can get: Playwright browser downloads, node-gyp rebuilds and husky routinely + * dominate install time and are each individually fixable. + * + * npm only — pnpm and yarn have no equivalent, and pnpm 11 no longer reads non-auth + * settings from .npmrc at all. Scraped on the next plugin start rather than during the + * install, because npm writes the file after our hooks have already run. + */ + +/** never let one weird log file produce a giant payload */ +const MAX_TIMERS = 500; +/** a single flush never looks at more than this many files */ +const MAX_FILES = 5; +const MAX_AGE_MS = 7 * 24 * 60 * 60 * 1000; + +interface NpmTimingFile { + metadata?: { command?: string[]; version?: string; timers?: Record }; + timers?: Record; +} + +const logsDir = (): string => + process.env.npm_config_logs_dir ?? join(homedir(), '.npm', '_logs'); + +const isInstallCommand = (command: string[] | undefined): boolean => { + const verb = command?.[0]; + return verb === 'install' || verb === 'ci' || verb === 'i' || verb === 'add'; +}; + +const trimTimers = (timers: Record): Record => { + const entries = Object.entries(timers).filter(([, v]) => typeof v === 'number'); + if (entries.length <= MAX_TIMERS) return Object.fromEntries(entries); + // keep the slowest, they are the ones anyone would act on + return Object.fromEntries(entries.sort((a, b) => b[1] - a[1]).slice(0, MAX_TIMERS)); +}; + +/** + * Emit one `install` event per npm run we have not seen before. Best effort throughout: + * no logs directory, no timing files, or a shape we don't recognise are all no-ops. + */ +export const collectNpmTimings = async (root?: string): Promise => { + let dir: string; + let files: string[]; + try { + dir = logsDir(); + files = readdirSync(dir).filter((f) => f.endsWith('-timing.json')); + } catch { + return; + } + if (files.length === 0) return; + + const state = readState(root); + const watermark = state?.npmTimingWatermark ?? Date.now() - MAX_AGE_MS; + + const fresh: Array<{ path: string; mtimeMs: number }> = []; + for (const file of files) { + try { + const path = join(dir, file); + const { mtimeMs } = statSync(path); + if (mtimeMs > watermark) fresh.push({ path, mtimeMs }); + } catch { + /* skip */ + } + } + if (fresh.length === 0) return; + + fresh.sort((a, b) => a.mtimeMs - b.mtimeMs); + const batch = fresh.slice(-MAX_FILES); + let highWater = watermark; + + for (const { path, mtimeMs } of batch) { + highWater = Math.max(highWater, mtimeMs); + try { + const parsed = JSON.parse(readFileSync(path, 'utf8')) as NpmTimingFile; + const timers = parsed.timers ?? parsed.metadata?.timers; + const command = parsed.metadata?.command; + if (!timers || !isInstallCommand(command)) continue; + + const total = timers['npm'] ?? timers['command:install'] ?? timers['reify']; + if (typeof total !== 'number') continue; + + const event: CommandBuildData = { + ...getCommonMetadata(total, 'install'), + type: 'command', + phase: 'install', + command: `npm ${(command ?? ['install']).join(' ')}`, + exitCode: 0, + success: true, + packageManager: 'npm', + packageManagerVersion: parsed.metadata?.version, + measurementSource: 'npm-timing', + npmTimers: trimTimers(timers), + // the run happened when npm wrote the file, not now + spooledAt: Math.round(mtimeMs), + }; + await sendCommandData(event); + } catch { + /* skip unreadable or unexpected file */ + } + } + + // record the watermark even for files we skipped, so we never re-read them + for (const { mtimeMs } of fresh) highWater = Math.max(highWater, mtimeMs); + const latest = readState(root); + writeState( + { + ...(latest ?? { sessionId: getSessionId(root), lastSeenAt: Date.now() }), + npmTimingWatermark: highWater, + }, + root, + ); +}; diff --git a/packages/common/src/lib/session.spec.ts b/packages/common/src/lib/session.spec.ts new file mode 100644 index 0000000..601bd03 --- /dev/null +++ b/packages/common/src/lib/session.spec.ts @@ -0,0 +1,126 @@ +import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest'; +import { + mkdtempSync, + mkdirSync, + rmSync, + readFileSync, + writeFileSync, + existsSync, +} from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; + +import { + _resetSessionCache, + getSessionId, + readState, + stateDir, + stateDirs, + writeState, +} from './session'; + +const FOUR_HOURS = 4 * 60 * 60 * 1000; + +describe('session', () => { + let root: string; + + beforeEach(() => { + root = mkdtempSync(join(tmpdir(), 'devfeedback-test-')); + _resetSessionCache(); + delete process.env.DEVFEEDBACK_SESSION_ID; + }); + + afterEach(() => { + rmSync(root, { recursive: true, force: true }); + vi.restoreAllMocks(); + }); + + it('falls back to a tmpdir keyed by repo path while node_modules is absent', () => { + const dir = stateDir(root); + expect(dir).not.toContain(join(root, 'node_modules')); + expect(dir.startsWith(tmpdir())).toBe(true); + }); + + it('prefers the node_modules cache once it exists, but still reads the tmpdir', () => { + const tmpDir = stateDirs(root)[0] as string; + mkdirSync(join(root, 'node_modules'), { recursive: true }); + + const dirs = stateDirs(root); + expect(dirs[0]).toBe(join(root, 'node_modules', '.cache', 'devfeedback')); + expect(dirs).toContain(tmpDir); + }); + + it('reads state written before node_modules existed', () => { + // the cold-install case: preinstall writes to tmp, postinstall reads after linking + writeState({ sessionId: 'cold-session', lastSeenAt: Date.now() }, root); + mkdirSync(join(root, 'node_modules'), { recursive: true }); + + expect(readState(root)?.sessionId).toBe('cold-session'); + }); + + it('writes state atomically, leaving no temp file behind', () => { + writeState({ sessionId: 'abc', lastSeenAt: 1 }, root); + const dir = stateDir(root); + expect(JSON.parse(readFileSync(join(dir, 'state.json'), 'utf8'))).toEqual({ + sessionId: 'abc', + lastSeenAt: 1, + }); + expect(existsSync(join(dir, `state.${process.pid}.tmp`))).toBe(false); + }); + + it('reuses a recent session id', () => { + writeState({ sessionId: 'existing', lastSeenAt: Date.now() - 1000 }, root); + expect(getSessionId(root)).toBe('existing'); + }); + + it('starts a new session after the idle gap', () => { + writeState({ sessionId: 'stale', lastSeenAt: Date.now() - FOUR_HOURS - 1 }, root); + const id = getSessionId(root); + expect(id).not.toBe('stale'); + expect(readState(root)?.sessionId).toBe(id); + }); + + it('lets DEVFEEDBACK_SESSION_ID win', () => { + process.env.DEVFEEDBACK_SESSION_ID = 'from-shell'; + writeState({ sessionId: 'on-disk', lastSeenAt: Date.now() }, root); + expect(getSessionId(root)).toBe('from-shell'); + delete process.env.DEVFEEDBACK_SESSION_ID; + }); + + it('keeps the session for the process lifetime even past the idle gap', () => { + // a dev server started at 9am and saved to at 2pm reports the session it was born into + const first = getSessionId(root); + writeState({ sessionId: first, lastSeenAt: Date.now() - FOUR_HOURS - 1 }, root); + expect(getSessionId(root)).toBe(first); + }); + + it('does not touch disk on every call', () => { + getSessionId(root); + const before = readState(root)?.lastSeenAt; + for (let i = 0; i < 100; i++) getSessionId(root); + expect(readState(root)?.lastSeenAt).toBe(before); + }); + + it('preserves unrelated state fields when refreshing the session', () => { + writeState( + { + sessionId: 'existing', + lastSeenAt: Date.now() - 1000, + winProcTimeMethod: 'none', + lockfileHash: 'deadbeef', + }, + root, + ); + getSessionId(root); + const state = readState(root); + expect(state?.winProcTimeMethod).toBe('none'); + expect(state?.lockfileHash).toBe('deadbeef'); + }); + + it('never throws when the state file is corrupt', () => { + writeState({ sessionId: 'x', lastSeenAt: Date.now() }, root); + writeFileSync(join(stateDir(root), 'state.json'), '{ not json'); + expect(readState(root)).toBeUndefined(); + expect(() => getSessionId(root)).not.toThrow(); + }); +}); diff --git a/packages/common/src/lib/session.ts b/packages/common/src/lib/session.ts new file mode 100644 index 0000000..8dd5af3 --- /dev/null +++ b/packages/common/src/lib/session.ts @@ -0,0 +1,137 @@ +import { createHash, randomUUID } from 'node:crypto'; +import { existsSync, mkdirSync, readFileSync, renameSync, writeFileSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; + +/** idle gap that starts a new session */ +const SESSION_TTL_MS = 4 * 60 * 60 * 1000; +/** how often a live process refreshes lastSeenAt */ +const TOUCH_INTERVAL_MS = 5 * 60 * 1000; + +const STATE_FILE = 'state.json'; + +export interface SessionState { + sessionId: string; + lastSeenAt: number; + /** hash of the lockfile as of the end of the last observed install */ + lockfileHash?: string; + /** hash of the lockfile as observed by the preinstall hook of the current install */ + preInstallLockfileHash?: string; + /** which mechanism successfully read a process start time on this Windows machine */ + winProcTimeMethod?: 'wmic' | 'powershell' | 'none'; + /** set by the preinstall hook, consumed by the postinstall hook */ + installStartedAt?: number; + /** node_modules was absent when the current install started */ + installWasCold?: boolean; + /** the repo has a root postinstall hook, so the bundled one must not double-report */ + expectRootPostinstall?: boolean; + /** mtime watermark for npm's own timing logs */ + npmTimingWatermark?: number; +} + +const tmpStateDir = (repoRoot: string): string => + join( + tmpdir(), + `devfeedback-${createHash('sha1').update(repoRoot).digest('hex').slice(0, 12)}`, + ); + +const localStateDir = (repoRoot: string): string => + join(repoRoot, 'node_modules', '.cache', 'devfeedback'); + +/** + * Every directory that may hold state for this repo, most preferred first. + * + * `node_modules` may not exist yet — install runs before anything else — so a + * tmpdir keyed by repo path is used until it does. Readers check both, because + * an install that starts cold writes to tmp and finishes with `node_modules` + * present. + */ +export const stateDirs = (repoRoot: string = process.cwd()): string[] => { + const local = localStateDir(repoRoot); + const tmp = tmpStateDir(repoRoot); + return existsSync(join(repoRoot, 'node_modules')) ? [local, tmp] : [tmp]; +}; + +/** The directory writes go to. Created on demand. */ +export const stateDir = (repoRoot: string = process.cwd()): string => { + const dir = stateDirs(repoRoot)[0] as string; + mkdirSync(dir, { recursive: true }); + return dir; +}; + +export const readState = (repoRoot?: string): SessionState | undefined => { + for (const dir of stateDirs(repoRoot)) { + try { + return JSON.parse(readFileSync(join(dir, STATE_FILE), 'utf8')) as SessionState; + } catch { + /* try the next location */ + } + } + return undefined; +}; + +/** atomic: temp file + rename, so a concurrent reader never sees a half-written file */ +export const writeState = (state: SessionState, repoRoot?: string): void => { + try { + const dir = stateDir(repoRoot); + const tmp = join(dir, `state.${process.pid}.tmp`); + writeFileSync(tmp, JSON.stringify(state)); + renameSync(tmp, join(dir, STATE_FILE)); // atomic on POSIX; same-volume replace on Windows + } catch { + /* telemetry must never throw */ + } +}; + +let cachedSessionId: string | undefined; +let lastTouchAt = 0; + +/** + * Resolved once per process and then held in memory. The file TTL decides session + * boundaries for *new* processes only — a dev server started at 9am and saved to at 2pm + * still reports the session it was born into. + */ +export const getSessionId = (repoRoot?: string): string => { + if (cachedSessionId) { + // Keep the session alive for sibling processes, but at most once every few minutes + // and never inline: this call sits on the HMR path, which must do no synchronous + // filesystem work at all. + if (Date.now() - lastTouchAt > TOUCH_INTERVAL_MS) { + lastTouchAt = Date.now(); + const id = cachedSessionId; + setImmediate(() => { + const prev = readState(repoRoot); + if (prev?.sessionId === id) { + writeState({ ...prev, lastSeenAt: Date.now() }, repoRoot); + } + }); + } + return cachedSessionId; + } + + // 1. explicit env var wins — set once per shell/loop, or by any wrapper script + const fromEnv = process.env.DEVFEEDBACK_SESSION_ID; + if (fromEnv) { + cachedSessionId = fromEnv; + return fromEnv; + } + + // 2. zero-friction fallback: file-backed session that rotates after an idle gap + const prev = readState(repoRoot); + if (prev && Date.now() - prev.lastSeenAt < SESSION_TTL_MS) { + cachedSessionId = prev.sessionId; + } else { + cachedSessionId = randomUUID(); + } + lastTouchAt = Date.now(); + writeState( + { ...(prev ?? {}), sessionId: cachedSessionId, lastSeenAt: Date.now() }, + repoRoot, + ); + return cachedSessionId; +}; + +/** test seam — clears the process-lifetime memo */ +export const _resetSessionCache = (): void => { + cachedSessionId = undefined; + lastTouchAt = 0; +}; diff --git a/packages/common/src/lib/signals.ts b/packages/common/src/lib/signals.ts new file mode 100644 index 0000000..41c47ea --- /dev/null +++ b/packages/common/src/lib/signals.ts @@ -0,0 +1,47 @@ +import { spoolCommandData } from './spool'; +import type { CommandBuildData } from './types'; + +const SIGNALS: NodeJS.Signals[] = ['SIGINT', 'SIGTERM']; + +/** + * Record an aborted run without changing what Ctrl-C does. + * + * Two traps this avoids. An async POST loses the race with process exit, so the event + * is written synchronously to the spool instead. And merely attaching a SIGINT listener + * suppresses Node's default exit behaviour — a plugin that only listens leaves the dev + * server hanging — so once we have recorded the event we remove ourselves and, if + * nobody else is listening, re-raise the signal to get the default action back. + */ +export const onAbort = ( + build: (signal: NodeJS.Signals) => CommandBuildData, + root?: string, +): (() => void) => { + const handlers: Partial void>> = {}; + + const dispose = () => { + for (const signal of SIGNALS) { + const handler = handlers[signal]; + if (handler) process.removeListener(signal, handler); + delete handlers[signal]; + } + }; + + for (const signal of SIGNALS) { + const handler = () => { + try { + spoolCommandData(build(signal), root); + } catch { + /* telemetry must never throw, least of all on the way out */ + } + dispose(); + if (process.listenerCount(signal) === 0) { + // we were the only listener, so restore the default action + process.kill(process.pid, signal); + } + }; + handlers[signal] = handler; + process.once(signal, handler); + } + + return dispose; +}; diff --git a/packages/common/src/lib/spool.spec.ts b/packages/common/src/lib/spool.spec.ts new file mode 100644 index 0000000..49c26df --- /dev/null +++ b/packages/common/src/lib/spool.spec.ts @@ -0,0 +1,96 @@ +import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest'; +import { existsSync, mkdtempSync, readFileSync, rmSync, writeFileSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; + +import { flushSpool, spoolCommandData } from './spool'; +import { stateDir } from './session'; +import { sendCommandData } from './common'; +import type { CommandBuildData } from './types'; + +vi.mock('./common', () => ({ sendCommandData: vi.fn() })); +vi.mock('./npm-timing', () => ({ collectNpmTimings: vi.fn() })); + +const mockedSend = vi.mocked(sendCommandData); + +const event = (overrides: Partial = {}): CommandBuildData => + ({ + type: 'command', + phase: 'install', + command: 'pnpm/9.0.0', + exitCode: 0, + success: true, + timeTaken: 1234, + sessionId: 'session-1', + ...overrides, + }) as CommandBuildData; + +describe('spool', () => { + let root: string; + + beforeEach(() => { + root = mkdtempSync(join(tmpdir(), 'devfeedback-spool-')); + vi.clearAllMocks(); + }); + + afterEach(() => { + rmSync(root, { recursive: true, force: true }); + }); + + const spoolFile = () => join(stateDir(root), 'spool.ndjson'); + + it('appends one NDJSON line per event and stamps spooledAt', () => { + spoolCommandData(event(), root); + spoolCommandData(event({ phase: 'devserver' }), root); + + const lines = readFileSync(spoolFile(), 'utf8').trim().split('\n'); + expect(lines).toHaveLength(2); + expect(JSON.parse(lines[0] as string).spooledAt).toBeTypeOf('number'); + expect(JSON.parse(lines[1] as string).phase).toBe('devserver'); + }); + + it('delivers spooled events and removes the file', async () => { + spoolCommandData(event(), root); + await flushSpool(root); + + expect(mockedSend).toHaveBeenCalledTimes(1); + expect(mockedSend.mock.calls[0]?.[0]).toMatchObject({ phase: 'install' }); + expect(existsSync(spoolFile())).toBe(false); + }); + + it('drops events older than the maximum age', async () => { + const stale = { ...event(), spooledAt: Date.now() - 8 * 24 * 60 * 60 * 1000 }; + writeFileSync(spoolFile(), JSON.stringify(stale) + '\n'); + + await flushSpool(root); + expect(mockedSend).not.toHaveBeenCalled(); + }); + + it('skips malformed lines without losing the good ones', async () => { + writeFileSync( + spoolFile(), + `not json\n${JSON.stringify({ ...event(), spooledAt: Date.now() })}\n`, + ); + + await flushSpool(root); + expect(mockedSend).toHaveBeenCalledTimes(1); + }); + + it('never grows past the size cap', () => { + writeFileSync(spoolFile(), 'x'.repeat(257 * 1024)); + spoolCommandData(event(), root); + + expect(readFileSync(spoolFile(), 'utf8')).toBe('x'.repeat(257 * 1024)); + }); + + it('is a no-op when there is nothing spooled', async () => { + await expect(flushSpool(root)).resolves.toBeUndefined(); + expect(mockedSend).not.toHaveBeenCalled(); + }); + + it('never throws, whatever the event contains', () => { + const circular = event() as unknown as Record; + circular.self = circular; + expect(() => spoolCommandData(circular as never, root)).not.toThrow(); + }); +}); diff --git a/packages/common/src/lib/spool.ts b/packages/common/src/lib/spool.ts new file mode 100644 index 0000000..04545c9 --- /dev/null +++ b/packages/common/src/lib/spool.ts @@ -0,0 +1,85 @@ +import { + appendFileSync, + existsSync, + mkdirSync, + readFileSync, + renameSync, + statSync, + unlinkSync, +} from 'node:fs'; +import { join } from 'node:path'; +import { stateDir, stateDirs } from './session'; +import { sendCommandData } from './common'; +import { collectNpmTimings } from './npm-timing'; +import type { CommandBuildData } from './types'; + +const MAX_SPOOL_BYTES = 256 * 1024; +const MAX_AGE_MS = 7 * 24 * 60 * 60 * 1000; + +const SPOOL_FILE = 'spool.ndjson'; + +/** + * A synchronous, single small append — safe inside a signal handler and cheap enough + * for a postinstall hook. Anything that cannot afford to await the network writes here + * and lets the next devfeedback process deliver it. + */ +export const spoolCommandData = (data: CommandBuildData, root?: string): void => { + try { + const dir = stateDir(root); + mkdirSync(dir, { recursive: true }); + const p = join(dir, SPOOL_FILE); + if (existsSync(p) && statSync(p).size > MAX_SPOOL_BYTES) return; // drop, never grow unbounded + appendFileSync(p, JSON.stringify({ ...data, spooledAt: Date.now() }) + '\n'); + } catch { + /* telemetry must never throw */ + } +}; + +/** claim-by-rename so two concurrent processes can't double-send */ +const flushOne = async (p: string): Promise => { + if (!existsSync(p)) return; + const claimed = `${p}.${process.pid}.claim`; + try { + renameSync(p, claimed); + } catch { + return; // someone else won the race + } + try { + const lines = readFileSync(claimed, 'utf8').split('\n').filter(Boolean); + for (const line of lines) { + try { + const event = JSON.parse(line) as CommandBuildData & { spooledAt: number }; + if (Date.now() - event.spooledAt > MAX_AGE_MS) continue; + await sendCommandData(event); + } catch { + /* skip bad line */ + } + } + } catch { + /* unreadable claim file: drop it */ + } finally { + try { + unlinkSync(claimed); + } catch { + /* already gone */ + } + } +}; + +/** + * Deliver everything left behind by install hooks, aborted dev servers and npm's own + * timing logs. Always called as `void flushSpool()` from a point where the developer + * is already waiting on something else. + */ +export const flushSpool = async (root?: string): Promise => { + try { + // both the node_modules cache and the tmpdir fallback, because a cold install + // writes to tmp and everything afterwards writes to node_modules + for (const dir of stateDirs(root)) { + await flushOne(join(dir, SPOOL_FILE)); + } + await collectNpmTimings(root); + } catch { + /* telemetry must never throw */ + } +}; diff --git a/packages/common/src/lib/types.ts b/packages/common/src/lib/types.ts index 83680d1..70b24cb 100644 --- a/packages/common/src/lib/types.ts +++ b/packages/common/src/lib/types.ts @@ -1,5 +1,6 @@ export interface CommonMetadata { id: string; + sessionId: string; userName: string; cpuCount: number; hostname: string; @@ -54,3 +55,57 @@ export interface ViteBuildData extends CommonMetadata { bundleStats?: ViteBundleStats; file: string | null; } + +/** A phase of the local dev cycle that is measured as a single span. */ +export type CommandPhase = + | 'install' + | 'codegen' + | 'typecheck' + | 'lint' + | 'test' + | 'build' + | 'devserver' + | 'clientready'; + +export type PackageManager = 'npm' | 'yarn' | 'pnpm'; + +export interface CommandBuildData extends CommonMetadata { + type: 'command'; + phase: CommandPhase; + command: string; + exitCode: number; + success: boolean; + + // install-specific, all optional + packageManager?: PackageManager; + packageManagerVersion?: string; + /** node_modules absent beforehand */ + coldInstall?: boolean; + /** lockfile hash before vs after */ + lockfileChanged?: boolean; + /** + * Where the install measurement came from: + * - 'preinstall' exact span, root preinstall hook ran (most accurate) + * - 'postinstall' inferred from the package manager process start time + * - 'npm-timing' scraped from npm's own ~/.npm/_logs/*-timing.json + */ + measurementSource?: 'preinstall' | 'postinstall' | 'npm-timing'; + /** raw per-phase timers from `npm install --timing`, milliseconds */ + npmTimers?: Record; + + // dev server specific, all optional + /** Vite only: did this start (re)run dependency prebundling? undefined when unknown */ + prebundled?: boolean; + + // client-ready specific, all optional + domContentLoadedMs?: number; + firstContentfulPaintMs?: number; + + // outcome detail, all optional + /** 'SIGINT' = developer gave up waiting */ + signal?: string; + errorCount?: number; + + /** set by the spool when an event is delivered late */ + spooledAt?: number; +} diff --git a/packages/common/tsup.config.ts b/packages/common/tsup.config.ts index 612fc2c..8a8ac38 100644 --- a/packages/common/tsup.config.ts +++ b/packages/common/tsup.config.ts @@ -1,10 +1,16 @@ import { defineConfig } from 'tsup' export default defineConfig({ - entry: ['src/index.ts'], + entry: { + index: 'src/index.ts', + // install hooks are executed by the package manager rather than imported, so + // they need their own stable entry points under dist/hooks + 'hooks/preinstall': 'src/hooks/preinstall.ts', + 'hooks/postinstall': 'src/hooks/postinstall.ts', + }, format: ['cjs', 'esm'], splitting: true, sourcemap: true, clean: true, - dts: true, + dts: { entry: 'src/index.ts' }, }) diff --git a/packages/common/vite.config.ts b/packages/common/vite.config.ts new file mode 100644 index 0000000..cf5d7c4 --- /dev/null +++ b/packages/common/vite.config.ts @@ -0,0 +1,13 @@ +import { defineConfig } from 'vite'; + +export default defineConfig({ + plugins: [], + test: { + watch: false, + globals: true, + environment: 'node', + include: ['src/**/*.{test,spec}.{js,mjs,cjs,ts,mts,cts,jsx,tsx}'], + reporters: ['default'], + coverage: { reportsDirectory: './test-output/vitest/coverage', provider: 'v8' }, + }, +}); diff --git a/packages/rspack-plugin/src/lib/rsbuild-stats-plugin.spec.ts b/packages/rspack-plugin/src/lib/rsbuild-stats-plugin.spec.ts index 8b76c34..20c2674 100644 --- a/packages/rspack-plugin/src/lib/rsbuild-stats-plugin.spec.ts +++ b/packages/rspack-plugin/src/lib/rsbuild-stats-plugin.spec.ts @@ -3,12 +3,24 @@ import { describe, it, expect, vi, beforeEach } from 'vitest'; import { RsbuildBuildStatsPlugin } from './rsbuild-stats-plugin'; import { RsbuildPluginAPI } from '@rsbuild/core'; import { Rspack } from '@rsbuild/core'; -import { getCommonMetadata, sendBuildData } from 'agoda-devfeedback-common'; +import { + getCommonMetadata, + sendBuildData, + sendCommandData, + flushSpool, + onAbort, +} from 'agoda-devfeedback-common'; import type { RspackBuildData } from 'agoda-devfeedback-common'; vi.mock('agoda-devfeedback-common', () => ({ getCommonMetadata: vi.fn(), sendBuildData: vi.fn(), + sendCommandData: vi.fn(), + flushSpool: vi.fn(), + onAbort: vi.fn(), + debugLog: vi.fn(), + debugWarn: vi.fn(), + debugError: vi.fn(), })); const mockedGetCommonMetadata = vi.mocked(getCommonMetadata); @@ -39,7 +51,9 @@ const createMockApi = (): Partial => { onAfterBuild: vi.fn(), onCloseBuild: vi.fn(), onBeforeStartDevServer: vi.fn(), + onAfterStartDevServer: vi.fn(), onDevCompileDone: vi.fn(), + modifyHTMLTags: vi.fn(), context: { version: '1.0.0', rootPath: '/mock/root', @@ -120,4 +134,55 @@ describe('RsbuildBuildStatsPlugin', () => { // Restore process.env process.env = originalEnv; }); + + describe('dev server lifecycle', () => { + it('reports time to a usable dev server', async () => { + await RsbuildBuildStatsPlugin.setup(mockApi as RsbuildPluginAPI); + + (mockApi.onBeforeStartDevServer as any).mock.calls[0][0](); + await (mockApi.onAfterStartDevServer as any).mock.calls[0][0](); + + expect(vi.mocked(sendCommandData)).toHaveBeenCalledWith( + expect.objectContaining({ + type: 'command', + phase: 'devserver', + command: 'rsbuild dev', + exitCode: 0, + success: true, + }), + ); + expect(vi.mocked(flushSpool)).toHaveBeenCalled(); + }); + + it('records a dev server the developer gave up on', async () => { + await RsbuildBuildStatsPlugin.setup(mockApi as RsbuildPluginAPI); + // dev only: a production build must not register the handler + expect(vi.mocked(onAbort)).not.toHaveBeenCalled(); + (mockApi.onBeforeStartDevServer as any).mock.calls[0][0](); + + const build = vi.mocked(onAbort).mock.calls[0]?.[0] as ( + signal: NodeJS.Signals, + ) => Record; + expect(build('SIGINT')).toMatchObject({ + type: 'command', + phase: 'devserver', + exitCode: 130, + success: false, + signal: 'SIGINT', + }); + }); + + it('injects a client script carrying the runtime WebSocket port', async () => { + await RsbuildBuildStatsPlugin.setup(mockApi as RsbuildPluginAPI); + // the listen callback is async, so wait a tick for the port to be assigned + await new Promise((resolve) => setTimeout(resolve, 50)); + + const modify = (mockApi.modifyHTMLTags as any).mock.calls[0][0]; + const params = { headTags: [] as any[] }; + modify(params); + + expect(params.headTags).toHaveLength(1); + expect(params.headTags[0].children).toContain('WebSocket'); + }); + }); }); diff --git a/packages/rspack-plugin/src/lib/rsbuild-stats-plugin.ts b/packages/rspack-plugin/src/lib/rsbuild-stats-plugin.ts index 0fa3464..a49a96d 100644 --- a/packages/rspack-plugin/src/lib/rsbuild-stats-plugin.ts +++ b/packages/rspack-plugin/src/lib/rsbuild-stats-plugin.ts @@ -3,15 +3,33 @@ import { RsbuildPlugin, RsbuildPluginAPI } from '@rsbuild/core'; import { WebSocketServer } from 'ws'; import path from 'node:path'; import { createServer } from 'node:http'; -import { getCommonMetadata, sendBuildData } from 'agoda-devfeedback-common'; -import type { RspackBuildData, DevFeedbackEvent } from 'agoda-devfeedback-common'; +import { + debugError, + debugLog, + debugWarn, + flushSpool, + getCommonMetadata, + onAbort, + sendBuildData, + sendCommandData, +} from 'agoda-devfeedback-common'; +import type { + CommandBuildData, + RspackBuildData, + DevFeedbackEvent, +} from 'agoda-devfeedback-common'; import { Rspack, rspack } from '@rsbuild/core'; +/** client events that arrive between compiles must not grow without bound */ +const MAX_CARRIED_EVENTS = 100; + export const RsbuildBuildStatsPlugin: RsbuildPlugin = { name: 'RsbuildBuildStatsPlugin', async setup(api: RsbuildPluginAPI) { const customIdentifier = process.env.npm_lifecycle_event; let devFeedbackBuffer: DevFeedbackEvent[] = []; + let devServerStart = 0; + let wsPort: number | undefined; // Retrieve the Rsbuild core version from the context const rspackVersion = api.context.version; @@ -21,8 +39,8 @@ export const RsbuildBuildStatsPlugin: RsbuildPlugin = { const wsServer = new WebSocketServer({ server: httpServer }); httpServer.listen(0, () => { - const port = (httpServer.address() as any)?.port; - console.log(`[DevFeedback] WebSocket server on port ${port}`); + wsPort = (httpServer.address() as any)?.port; + debugLog(`[DevFeedback] WebSocket server on port ${wsPort}`); }); wsServer.on('connection', (socket) => { @@ -40,7 +58,7 @@ export const RsbuildBuildStatsPlugin: RsbuildPlugin = { api.onAfterBuild(async (params) => { const { stats } = params; if (!stats) { - console.warn('[RsbuildBuildStatsPlugin] Warning: Stats object is undefined.'); + debugWarn('[RsbuildBuildStatsPlugin] Warning: Stats object is undefined.'); return; } await processStats(stats); @@ -48,15 +66,67 @@ export const RsbuildBuildStatsPlugin: RsbuildPlugin = { // Hook into the dev server start api.onBeforeStartDevServer(() => { - console.log('[RsbuildBuildStatsPlugin] Development server is starting...'); - devFeedbackBuffer = []; + debugLog('[RsbuildBuildStatsPlugin] Development server is starting...'); + devServerStart = Date.now(); + // A restart before the first compile completes would otherwise silently drop + // every client event the previous server collected, so carry them forward. + devFeedbackBuffer = devFeedbackBuffer.slice(-MAX_CARRIED_EVENTS); + registerAbortHandler(); + }); + + // Time to a usable dev server — the number a developer actually waits for, and the + // one measurement this plugin never had. + api.onAfterStartDevServer?.(async () => { + await sendCommandData({ + ...getCommonMetadata(Date.now() - devServerStart, customIdentifier), + type: 'command', + phase: 'devserver', + command: 'rsbuild dev', + exitCode: 0, + success: true, + }); + void flushSpool(); + }); + + // Dev only. Ctrl-C during a production build is a different story and does not + // belong in the devserver phase. + let abortRegistered = false; + function registerAbortHandler() { + if (abortRegistered) return; + abortRegistered = true; + onAbort( + (signal): CommandBuildData => ({ + ...getCommonMetadata( + devServerStart ? Date.now() - devServerStart : 0, + customIdentifier, + ), + type: 'command', + phase: 'devserver', + command: 'rsbuild dev', + exitCode: 130, + success: false, + signal, + }), + ); + } + + // Give the browser a way to report back. The port is only known at runtime, so it + // has to be injected rather than baked into a static client script. + api.modifyHTMLTags?.((params: any) => { + if (!wsPort) return params; + params.headTags?.push({ + tag: 'script', + attrs: { type: 'module' }, + children: clientScript(wsPort), + }); + return params; }); // Hook into the dev server compile done api.onDevCompileDone(async (params) => { const { stats } = params; if (!stats) { - console.warn('[RsbuildBuildStatsPlugin] Warning: Stats object is undefined.'); + debugWarn('[RsbuildBuildStatsPlugin] Warning: Stats object is undefined.'); return; } await processStats(stats); @@ -68,6 +138,29 @@ export const RsbuildBuildStatsPlugin: RsbuildPlugin = { httpServer.close(); }); + function clientScript(port: number): string { + return ` + (() => { + try { + const socket = new WebSocket('ws://' + location.hostname + ':${port}'); + const send = (type, elapsedMs) => { + if (typeof elapsedMs !== 'number') return; + try { socket.send(JSON.stringify({ type, elapsedMs })); } catch {} + }; + socket.addEventListener('open', () => { + (('requestIdleCallback' in window) ? requestIdleCallback : setTimeout)(() => { + const nav = performance.getEntriesByType('navigation')[0]; + const fcp = performance.getEntriesByName('first-contentful-paint')[0]; + send('clientReady', performance.now()); + send('domContentLoaded', nav && nav.domContentLoadedEventEnd); + send('firstContentfulPaint', fcp && fcp.startTime); + }, 0); + }); + } catch {} + })(); + `; + } + // Shared function to process stats async function processStats(stats: Rspack.Stats | Rspack.MultiStats) { recordEvent(stats, { type: 'compileDone' }); @@ -88,9 +181,10 @@ export const RsbuildBuildStatsPlugin: RsbuildPlugin = { nbrOfRebuiltModules: modulesCount.rebuilt, devFeedback: devFeedbackBuffer, }; + devFeedbackBuffer = []; // Send everything to your existing endpoint - sendBuildData(buildStats); + await sendBuildData(buildStats); } // Helper function to record events @@ -115,12 +209,12 @@ export const RsbuildBuildStatsPlugin: RsbuildPlugin = { try { const parsed = JSON.parse(rawMsg) as DevFeedbackEvent; devFeedbackBuffer.push(parsed); - console.log( + debugLog( `[DevFeedback] Client event: ${parsed.type}, elapsedMs=${parsed.elapsedMs}`, ); } catch (err) { // Ignore parse errors - console.error('[DevFeedback] Error parsing incoming WebSocket message:', err); + debugError('[DevFeedback] Error parsing incoming WebSocket message:', err); } } @@ -163,7 +257,10 @@ export const RsbuildBuildStatsPlugin: RsbuildPlugin = { } // Count cached modules - function getModulesCount(stats?: Rspack.Stats | Rspack.MultiStats): { cached: number, rebuilt: number } { + function getModulesCount(stats?: Rspack.Stats | Rspack.MultiStats): { + cached: number; + rebuilt: number; + } { const counts = { cached: 0, rebuilt: 0, @@ -171,7 +268,8 @@ export const RsbuildBuildStatsPlugin: RsbuildPlugin = { if (!stats) return counts; const allStats = stats instanceof rspack.MultiStats ? stats.stats : [stats]; allStats.forEach((stats) => { - stats.toJson().modules?.forEach((module) => { + // without a preset this serializes the entire compilation on every rebuild + stats.toJson({ preset: 'none', modules: true }).modules?.forEach((module) => { if (module.built) { counts.rebuilt++; } else if (module.cached) { diff --git a/packages/rspack-plugin/src/lib/rspack-stats-plugin.spec.ts b/packages/rspack-plugin/src/lib/rspack-stats-plugin.spec.ts index 1c01839..6954cd9 100644 --- a/packages/rspack-plugin/src/lib/rspack-stats-plugin.spec.ts +++ b/packages/rspack-plugin/src/lib/rspack-stats-plugin.spec.ts @@ -8,6 +8,12 @@ import type { RspackBuildData } from 'agoda-devfeedback-common'; vi.mock('agoda-devfeedback-common', () => ({ getCommonMetadata: vi.fn(), sendBuildData: vi.fn(), + sendCommandData: vi.fn(), + flushSpool: vi.fn(), + onAbort: vi.fn(), + debugLog: vi.fn(), + debugWarn: vi.fn(), + debugError: vi.fn(), })); const mockedGetCommonMetadata = vi.mocked(getCommonMetadata); diff --git a/packages/rspack-plugin/src/lib/rspack-stats-plugin.ts b/packages/rspack-plugin/src/lib/rspack-stats-plugin.ts index fd283aa..3421089 100644 --- a/packages/rspack-plugin/src/lib/rspack-stats-plugin.ts +++ b/packages/rspack-plugin/src/lib/rspack-stats-plugin.ts @@ -2,8 +2,20 @@ import { Compiler, Stats, StatsCompilation } from '@rspack/core'; import { WebSocketServer, Server as WebSocketServerType } from 'ws'; import path from 'node:path'; import { createServer, Server as HttpServerType } from 'node:http'; -import { getCommonMetadata, sendBuildData } from 'agoda-devfeedback-common'; -import type { RspackBuildData, DevFeedbackEvent } from 'agoda-devfeedback-common'; +import { + debugError, + debugLog, + flushSpool, + getCommonMetadata, + onAbort, + sendBuildData, + sendCommandData, +} from 'agoda-devfeedback-common'; +import type { + CommandBuildData, + RspackBuildData, + DevFeedbackEvent, +} from 'agoda-devfeedback-common'; class RspackBuildStatsPlugin { private customIdentifier: string; @@ -11,6 +23,10 @@ class RspackBuildStatsPlugin { private wsServer: WebSocketServerType; private httpServer: HttpServerType; private toolVersion: string = ''; + private watchStart: number | undefined; + private firstWatchCompileReported = false; + private abortRegistered = false; + private flushedOnce = false; constructor(options: { customIdentifier?: string } = {}) { this.customIdentifier = @@ -34,17 +50,19 @@ class RspackBuildStatsPlugin { preset: 'none', modules: true, }); - this.processStats(stats, statsJson); + await this.processStats(stats, statsJson); callback(); }); compiler.hooks.watchRun.tap(pluginName, () => { this.devFeedbackBuffer = []; - console.log('[RspackBuildStatsPlugin] Watching for changes...'); + if (this.watchStart === undefined) this.watchStart = Date.now(); + debugLog('[RspackBuildStatsPlugin] Watching for changes...'); + this.registerAbortHandler(); }); compiler.hooks.failed.tap(pluginName, (error) => { - console.error('[RspackBuildStatsPlugin] Compilation failed:', error); + debugError('[RspackBuildStatsPlugin] Compilation failed:', error); }); // Cleanup @@ -54,11 +72,31 @@ class RspackBuildStatsPlugin { }); } + /** Ctrl-C during watch is a developer giving up on a rebuild; that is worth recording. */ + private registerAbortHandler() { + if (this.abortRegistered) return; + this.abortRegistered = true; + onAbort( + (signal): CommandBuildData => ({ + ...getCommonMetadata( + this.watchStart ? Date.now() - this.watchStart : 0, + this.customIdentifier, + ), + type: 'command', + phase: 'devserver', + command: 'rspack watch', + exitCode: 130, + success: false, + signal, + }), + ); + } + private setupWebSocketServer() { this.httpServer.listen(0, () => { const address = this.httpServer.address(); const port = typeof address === 'object' ? address?.port : null; - console.log(`[DevFeedback] WebSocket server on port ${port}`); + debugLog(`[DevFeedback] WebSocket server on port ${port}`); }); this.wsServer.on('connection', (socket) => { @@ -86,6 +124,27 @@ class RspackBuildStatsPlugin { }; await sendBuildData(buildStats); + + // In watch mode the first completed compile is the moment the developer can use + // the app; it is also the first safe point to deliver anything the install or a + // previous Ctrl-C left in the spool. + if (this.watchStart !== undefined && !this.firstWatchCompileReported) { + this.firstWatchCompileReported = true; + await sendCommandData({ + ...getCommonMetadata(Date.now() - this.watchStart, this.customIdentifier), + type: 'command', + phase: 'devserver', + command: 'rspack watch', + exitCode: 0, + success: true, + }); + } + + // once per process only — every rebuild must stay free of extra filesystem work + if (!this.flushedOnce) { + this.flushedOnce = true; + void flushSpool(); + } } private recordEvent(stats: Stats, partial: Omit) { @@ -105,12 +164,12 @@ class RspackBuildStatsPlugin { try { const parsed = JSON.parse(rawMsg) as DevFeedbackEvent; this.devFeedbackBuffer.push(parsed); - console.log( + debugLog( `[DevFeedback] Client event: ${parsed.type}, elapsedMs=${parsed.elapsedMs}`, ); } catch (err) { // Ignore parse errors - console.error('[DevFeedback] Error parsing incoming message:', err); + debugError('[DevFeedback] Error parsing incoming message:', err); } } diff --git a/packages/vite-plugin/package.json b/packages/vite-plugin/package.json index 5efc5be..2012f34 100644 --- a/packages/vite-plugin/package.json +++ b/packages/vite-plugin/package.json @@ -32,8 +32,8 @@ "rollup": "4.39.0" }, "peerDependencies": { - "vite": ">=5.0.0", - "rollup": ">=4.0.0" + "vite": ">=4.0.0", + "rollup": ">=3.0.0" }, "publishConfig": { "access": "public" diff --git a/packages/vite-plugin/src/lib/vite-build-stats-plugin.spec.ts b/packages/vite-plugin/src/lib/vite-build-stats-plugin.spec.ts index bd278b2..cde662f 100644 --- a/packages/vite-plugin/src/lib/vite-build-stats-plugin.spec.ts +++ b/packages/vite-plugin/src/lib/vite-build-stats-plugin.spec.ts @@ -6,17 +6,30 @@ import type { ViteDevServer } from 'vite'; import { viteBuildStatsPlugin } from './vite-build-stats-plugin'; import type { CommonMetadata, ViteBuildData } from 'agoda-devfeedback-common'; -import { getCommonMetadata, sendBuildData } from 'agoda-devfeedback-common'; +import { + getCommonMetadata, + sendBuildData, + sendCommandData, + flushSpool, + onAbort, +} from 'agoda-devfeedback-common'; import { generateViteOutputBundleData } from '../utils/test-data-generator.js'; // Mock common dependencies vi.mock('agoda-devfeedback-common', () => ({ getCommonMetadata: vi.fn(), sendBuildData: vi.fn(), + sendCommandData: vi.fn(), + flushSpool: vi.fn(), + onAbort: vi.fn(), + debugError: vi.fn(), })); const mockedGetCommonMetadata = vi.mocked(getCommonMetadata); const mockedSendBuildData = vi.mocked(sendBuildData); +const mockedSendCommandData = vi.mocked(sendCommandData); +const mockedFlushSpool = vi.mocked(flushSpool); +const mockedOnAbort = vi.mocked(onAbort); // Mock request/response classes for HMR testing class MockRequest extends EventEmitter { @@ -290,5 +303,102 @@ describe('viteBuildStatsPlugin', () => { expect(content).toContain('createHotContext'); expect(content).toContain('vite:afterUpdate'); }); + + it('should ask the client to report when the app is usable', () => { + const content = plugin.load?.('/@vite-timing/hmr'); + expect(content).toContain('/__vite_timing_ready'); + expect(content).toContain('first-contentful-paint'); + }); + }); + + describe('dev server lifecycle', () => { + let httpServer: EventEmitter; + + beforeEach(() => { + httpServer = new EventEmitter(); + mockServer = { + watcher: mockWatcher, + httpServer: httpServer as unknown as ViteDevServer['httpServer'], + middlewares: { use: vi.fn() }, + } as Partial; + mockedGetCommonMetadata.mockReturnValue({} as CommonMetadata); + }); + + it('reports time to a usable dev server once it is listening', () => { + plugin.configureServer?.(mockServer as ViteDevServer); + expect(mockedSendCommandData).not.toHaveBeenCalled(); + + httpServer.emit('listening'); + + expect(mockedSendCommandData).toHaveBeenCalledWith( + expect.objectContaining({ + type: 'command', + phase: 'devserver', + command: 'vite dev', + exitCode: 0, + success: true, + }), + ); + }); + + it('delivers spooled install and abort events once the server is up', () => { + plugin.configureServer?.(mockServer as ViteDevServer); + httpServer.emit('listening'); + expect(mockedFlushSpool).toHaveBeenCalled(); + }); + + it('registers an abort handler that records a given-up dev server', () => { + plugin.configureServer?.(mockServer as ViteDevServer); + + expect(mockedOnAbort).toHaveBeenCalled(); + const build = mockedOnAbort.mock.calls[0]?.[0] as ( + signal: NodeJS.Signals, + ) => Record; + expect(build('SIGINT')).toMatchObject({ + type: 'command', + phase: 'devserver', + exitCode: 130, + success: false, + signal: 'SIGINT', + }); + }); + + it('reports client ready exactly once per server run', async () => { + plugin.configureServer?.(mockServer as ViteDevServer); + const handler = ( + mockServer.middlewares?.use as jest.Mock + ).mock.calls[0]?.[0] as MiddlewareHandler; + + const post = async () => { + const req = new MockRequest('/__vite_timing_ready'); + const res = new MockResponse(); + const done = new Promise((resolve) => { + res.end = vi.fn(() => resolve()); + }); + handler(req, res, vi.fn()); + req.emit( + 'data', + JSON.stringify({ + elapsedMs: 1200, + domContentLoaded: 900, + firstContentfulPaint: 1000, + }), + ); + req.emit('end'); + await done; + }; + + await post(); + await post(); + + const clientReady = mockedSendCommandData.mock.calls.filter( + (call) => (call[0] as { phase?: string }).phase === 'clientready', + ); + expect(clientReady).toHaveLength(1); + expect(clientReady[0]?.[0]).toMatchObject({ + domContentLoadedMs: 900, + firstContentfulPaintMs: 1000, + }); + }); }); }); diff --git a/packages/vite-plugin/src/lib/vite-build-stats-plugin.ts b/packages/vite-plugin/src/lib/vite-build-stats-plugin.ts index a3dcbdc..0b86a3d 100644 --- a/packages/vite-plugin/src/lib/vite-build-stats-plugin.ts +++ b/packages/vite-plugin/src/lib/vite-build-stats-plugin.ts @@ -1,11 +1,23 @@ -import { type Plugin, ViteDevServer } from 'vite'; +import { type Plugin, type ResolvedConfig, ViteDevServer } from 'vite'; import { NormalizedOutputOptions, OutputBundle } from 'rollup'; import { Blob } from 'node:buffer'; import path from 'node:path'; +import { statSync } from 'node:fs'; import type { IncomingMessage, ServerResponse } from 'http'; -import type { ViteBuildData, ViteBundleStats } from 'agoda-devfeedback-common'; -import { getCommonMetadata, sendBuildData } from 'agoda-devfeedback-common'; +import type { + CommandBuildData, + ViteBuildData, + ViteBundleStats, +} from 'agoda-devfeedback-common'; +import { + debugError, + flushSpool, + getCommonMetadata, + onAbort, + sendBuildData, + sendCommandData, +} from 'agoda-devfeedback-common'; interface TimingEntry { file: string; @@ -17,10 +29,19 @@ interface ClientMessage { clientTimestamp: number; } +interface ClientReadyMessage { + elapsedMs?: number; + domContentLoaded?: number; + firstContentfulPaint?: number; +} + export interface ViteTimingPlugin extends Plugin { _TEST_getChangeMap?: () => Map; } +const HMR_COMPLETE_PATH = '/__vite_timing_hmr_complete'; +const CLIENT_READY_PATH = '/__vite_timing_ready'; + export function viteBuildStatsPlugin( customIdentifier: string | undefined = process.env.npm_lifecycle_event, bootstrapBundleSizeLimitKb?: number, @@ -29,12 +50,40 @@ export function viteBuildStatsPlugin( let buildEnd: number; let bootstrapChunkSizeBytes: number | undefined = undefined; let rollupVersion: string | undefined = undefined; + let root: string | undefined = undefined; + let depsMetaMtimeBefore: number | undefined = undefined; + let clientReadyReported = false; const changeMap = new Map(); const normalizePath = (filePath: string): string => { return filePath.replace(/\\/g, '/').replace(/^\/+/, ''); }; + /** + * Dependency prebundling is usually the dominant cold-start cost, and its metadata + * file is rewritten only when prebundling actually ran. Strictly best effort — under + * Rolldown-based Vite the file may not exist at all, so the flag stays undefined + * rather than guessing. Never reach into server internals for this. + */ + const depsMetaMtime = (): number | undefined => { + try { + return statSync( + path.join(root ?? process.cwd(), 'node_modules/.vite/deps/_metadata.json'), + ).mtimeMs; + } catch { + return undefined; + } + }; + + const readBody = (req: IncomingMessage): Promise => + new Promise((resolve) => { + let body = ''; + req.on('data', (chunk) => { + body += chunk.toString(); + }); + req.on('end', () => resolve(body)); + }); + const clientScript = { virtualHmrModule: ` import { createHotContext as __vite__createHotContext } from '/@vite/client'; @@ -45,16 +94,16 @@ export function viteBuildStatsPlugin( data.updates.forEach(update => { if (update.path) { const endTime = Date.now(); - fetch('/__vite_timing_hmr_complete', { + fetch('${HMR_COMPLETE_PATH}', { method: 'POST', - headers: { + headers: { 'Content-Type': 'application/json', 'X-Requested-With': 'XMLHttpRequest', - 'X-Silent': 'true' + 'X-Silent': 'true' }, - body: JSON.stringify({ + body: JSON.stringify({ file: update.path, - clientTimestamp: endTime + clientTimestamp: endTime }) }).catch(err => console.error('[vite-timing] Failed to send metrics:', err)); } @@ -62,13 +111,73 @@ export function viteBuildStatsPlugin( } }); } + + // time to app usable: reported once, from an idle callback, so it never competes + // with the app's own startup work + (('requestIdleCallback' in window) ? requestIdleCallback : setTimeout)(() => { + const nav = performance.getEntriesByType('navigation')[0]; + const fcp = performance.getEntriesByName('first-contentful-paint')[0]; + fetch('${CLIENT_READY_PATH}', { + method: 'POST', + headers: { 'Content-Type': 'application/json', 'X-Silent': 'true' }, + body: JSON.stringify({ + elapsedMs: performance.now(), + domContentLoaded: nav && nav.domContentLoadedEventEnd, + firstContentfulPaint: fcp && fcp.startTime, + }), + }).catch(() => {}); + }, 0); `, }; const plugin: ViteTimingPlugin = { name: 'vite-plugin-agoda-build-reporter', + configResolved(config: ResolvedConfig) { + root = config.root; + depsMetaMtimeBefore = depsMetaMtime(); + }, + configureServer(server: ViteDevServer) { + const serverStart = Date.now(); + + // In dev mode closeBundle never fires, so without this the single number a + // developer actually waits for — time to a usable dev server — is never measured. + server.httpServer?.once('listening', () => { + const after = depsMetaMtime(); + const prebundled = + depsMetaMtimeBefore === undefined && after === undefined + ? undefined + : after !== depsMetaMtimeBefore; + + void sendCommandData({ + ...getCommonMetadata(Date.now() - serverStart, customIdentifier), + type: 'command', + phase: 'devserver', + command: 'vite dev', + exitCode: 0, + success: true, + ...(prebundled === undefined ? {} : { prebundled }), + }); + + // deliver whatever install, or a previous Ctrl-C, left behind + void flushSpool(root); + }); + + // A dev server the developer gave up on is data, not an absence of data. + onAbort( + (signal): CommandBuildData => ({ + ...getCommonMetadata(Date.now() - serverStart, customIdentifier), + type: 'command', + phase: 'devserver', + command: 'vite dev', + exitCode: 130, + success: false, + signal, + }), + root, + ); + server.watcher.on('change', (file: string) => { const timestamp = Date.now(); const relativePath = normalizePath(path.relative(process.cwd(), file)); @@ -80,12 +189,8 @@ export function viteBuildStatsPlugin( }); server.middlewares.use((req: IncomingMessage, res: ServerResponse, next) => { - if (req.url === '/__vite_timing_hmr_complete') { - let body = ''; - req.on('data', (chunk) => { - body += chunk.toString(); - }); - req.on('end', async () => { + if (req.url === HMR_COMPLETE_PATH) { + void readBody(req).then(async (body) => { try { const { file, clientTimestamp } = JSON.parse(body) as ClientMessage; const normalizedFile = normalizePath(file); @@ -122,7 +227,7 @@ export function viteBuildStatsPlugin( ); } } catch (err) { - console.error('[vite-timing] Error processing timing data:', err); + debugError('[vite-timing] Error processing timing data:', err); res.writeHead(500, { 'Content-Type': 'application/json' }); res.end( JSON.stringify({ @@ -132,6 +237,33 @@ export function viteBuildStatsPlugin( ); } }); + } else if (req.url === CLIENT_READY_PATH) { + void readBody(req).then(async (body) => { + try { + // one report per server run: a reload is not a new dev server start + if (!clientReadyReported) { + clientReadyReported = true; + const payload = JSON.parse(body) as ClientReadyMessage; + await sendCommandData({ + ...getCommonMetadata( + Math.round(Date.now() - serverStart), + customIdentifier, + ), + type: 'command', + phase: 'clientready', + command: 'vite dev', + exitCode: 0, + success: true, + domContentLoadedMs: payload.domContentLoaded, + firstContentfulPaintMs: payload.firstContentfulPaint, + }); + } + } catch (err) { + debugError('[vite-timing] Error processing client ready data:', err); + } + res.writeHead(204); + res.end(); + }); } else { next(); } @@ -202,6 +334,9 @@ export function viteBuildStatsPlugin( }; await sendBuildData(buildStats); + + // a production build is a fine moment to deliver a stale install event + void flushSpool(root); }, }; diff --git a/pnpm-lock.yaml b/pnpm-lock.yaml index a904eb7..6ceae60 100644 --- a/pnpm-lock.yaml +++ b/pnpm-lock.yaml @@ -85,7 +85,7 @@ importers: specifier: 2.8.1 version: 2.8.1 vite: - specifier: '>=5.0.0' + specifier: '>=4.0.0' version: 5.4.14(@types/node@22.14.0)(terser@5.39.0) devDependencies: '@repo/typescript-config':