Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Telemetry #408

Merged
merged 22 commits into from
Jan 11, 2024
Merged
Show file tree
Hide file tree
Changes from 16 commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 4 additions & 1 deletion package.json
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,7 @@
"deploy": "./bin/observable.ts deploy",
"test": "yarn test:mocha && yarn test:tsc && yarn test:lint && yarn test:prettier",
"test:coverage": "c8 yarn test:mocha",
"test:mocha": "rm -rf test/.observablehq/cache test/input/build/*/.observablehq/cache && tsx --no-warnings=ExperimentalWarning ./node_modules/.bin/mocha 'test/**/*-test.*'",
"test:mocha": "rm -rf test/.observablehq/cache test/input/build/*/.observablehq/cache && OBSERVABLE_TELEMETRY_DISABLE=1 tsx --no-warnings=ExperimentalWarning ./node_modules/.bin/mocha 'test/**/*-test.*'",
"test:lint": "eslint src test",
"test:prettier": "prettier --check src test",
"test:tsc": "tsc --noEmit",
Expand All @@ -49,12 +49,15 @@
"@rollup/plugin-node-resolve": "^15.2.3",
"acorn": "^8.11.2",
"acorn-walk": "^8.3.0",
"ci-info": "^4.0.0",
"esbuild": "^0.19.8",
"fast-array-diff": "^1.1.0",
"fast-deep-equal": "^3.1.3",
"gray-matter": "^4.0.3",
"he": "^1.2.0",
"highlight.js": "^11.8.0",
"is-docker": "^3.0.0",
"is-wsl": "^3.1.0",
"jszip": "^3.10.1",
"linkedom": "^0.15.6",
"markdown-it": "^13.0.2",
Expand Down
4 changes: 3 additions & 1 deletion src/build.ts
Original file line number Diff line number Diff line change
Expand Up @@ -60,7 +60,8 @@ export async function build(
{config, addPublic = true, clientEntry = "./src/client/index.js"}: BuildOptions,
effects: BuildEffects = new FileBuildEffects(config.output)
): Promise<void> {
const {root} = config;
const {root, telemetry} = config;
telemetry.record({event: "build", step: "start"});

// Make sure all files are readable before starting to write output files.
let pageCount = 0;
Expand Down Expand Up @@ -162,6 +163,7 @@ export async function build(
await effects.copyFile(sourcePath, outputPath);
}
}
telemetry.record({event: "build", step: "finish"});
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I bet this kind of "start/end" telemetry is going to often be interesting for us. Is it possible to link ends to their starts at all? Maybe telemetry.record could return a message ID that we could note in the end event?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

the session id will be stable across tied events.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So the workflow on the analytic side would be to find a start event, and then look for end events with the same session id? Will that be annoying if there is an event that happens multiple times in a telemetry session?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

oh, do you mean like in the case of maybe two builds happening concurrently and the events get interleaved?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I mean if we have a start event for something more granular, like one per page. Is that just not what this is for? Having average time-per-page and number-of-pages metrics would be useful.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yeah, we could do something like that. so just easier rolled-up timings of blocks of code, right? maybe a premature idea would be to provide a telemetry.measure({event: "something"}, () => { /* block */ }). I guess I'm still not sure exactly what we'll want to measure so am willing to iterate a bunch and probably throw out old data as we do.

Copy link
Member Author

@visnup visnup Jan 11, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I could return an identifier (a counter probably that just increases with every call to record) if people want to reference these in other events:

const ts = telemetry.record({event: "build", step: "start"});
// ...
telemetry.record({event: "build", step: "milestone", start: ts});

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The block version is familiar, but it feels heavy handed. I'd really like language support for something like destructors, which makes this very nice, but we don't have those.

I think the ts version makes sense, and I'd be happy with that.

Another idea I had was to have the return value of record be a function or object with methods so you could do something like

const telemetrySpan = telemetry.startSpan({event: "build", step: "start"});
// ...
telemetrySpan.note({step: "milestone", foo: "bar"});
// ...
telemetrySpan.end({step: "end", status: "success"})

That's probably overkill though. Having .record always give back an auto incrementing ID sounds like a good approach.

}

export class FileBuildEffects implements BuildEffects {
Expand Down
4 changes: 3 additions & 1 deletion src/config.ts
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@ import {readFile} from "node:fs/promises";
import {basename, dirname, extname, join} from "node:path";
import {visitFiles} from "./files.js";
import {parseMarkdown} from "./markdown.js";
import {Telemetry} from "./telemetry.js";
import {resolvePath} from "./url.js";

export interface Page {
Expand Down Expand Up @@ -34,6 +35,7 @@ export interface Config {
toc: TableOfContents;
style: null | Style; // defaults to {theme: ["light", "dark"]}
deploy: null | {workspace: string; project: string};
telemetry: Telemetry;
}

export async function readConfig(configPath?: string, root?: string): Promise<Config> {
Expand Down Expand Up @@ -83,7 +85,7 @@ export async function normalizeConfig(spec: any = {}, defaultRoot = "docs"): Pro
footer = String(footer);
toc = normalizeToc(toc);
deploy = deploy ? {workspace: String(deploy.workspace), project: String(deploy.project)} : null;
return {root, output, title, pages, pager, footer, toc, style, deploy};
return {root, output, title, pages, pager, footer, toc, style, deploy, telemetry: new Telemetry()};
visnup marked this conversation as resolved.
Show resolved Hide resolved
}

function normalizeTheme(spec: any): string[] {
Expand Down
3 changes: 3 additions & 0 deletions src/deploy.ts
Original file line number Diff line number Diff line change
Expand Up @@ -41,6 +41,8 @@ const defaultEffects: DeployEffects = {

/** Deploy a project to ObservableHQ */
export async function deploy({config}: DeployOptions, effects = defaultEffects): Promise<void> {
const {telemetry} = config;
telemetry.record({event: "deploy", step: "start"});
mythmon marked this conversation as resolved.
Show resolved Hide resolved
const {logger} = effects;
const apiKey = await effects.getObservableApiKey(logger);
const apiClient = new ObservableApiClient({apiKey});
Expand Down Expand Up @@ -131,6 +133,7 @@ export async function deploy({config}: DeployOptions, effects = defaultEffects):
// Mark the deploy as uploaded
const deployInfo = await apiClient.postDeployUploaded(deployId);
logger.log(`Deployed project now visible at ${blue(deployInfo.url)}`);
telemetry.record({event: "deploy", step: "finish"});
}

async function promptUserForInput(
Expand Down
1 change: 1 addition & 0 deletions src/preview.ts
Original file line number Diff line number Diff line change
Expand Up @@ -53,6 +53,7 @@ export class PreviewServer {
}

static async start({verbose = true, hostname, port, ...options}: PreviewOptions) {
options.config.telemetry.record({event: "preview", step: "start"});
const server = createServer();
if (port === undefined) {
for (port = 3000; true; ++port) {
Expand Down
177 changes: 177 additions & 0 deletions src/telemetry.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,177 @@
import {exec} from "node:child_process";
import {createHash, randomUUID} from "node:crypto";
import {readFile, writeFile} from "node:fs/promises";
import {join} from "node:path";
import os from "os";
import type {Logger} from "./logger.js";
import {cyan, magenta} from "./tty.js";

type uuid = ReturnType<typeof randomUUID>;
type TelemetryIds = {
device: uuid;
project: string;
session: uuid;
};
type TelemetryEnvironment = {
version: string;
systemPlatform: string;
systemRelease: string;
systemArchitecture: string;
cpuCount: number;
cpuModel: string | null;
cpuSpeed: number | null;
memoryInMb: number;
};
type TelemetryTime = {
now: number;
timeOrigin: number;
timeZoneOffset: number;
};
type TelemetryData = {
event: "build" | "deploy" | "preview";
step: "start" | "finish";
[key: string]: unknown;
};

let _config: Record<string, uuid> | undefined;
async function getPersistentId(name: string, generator = randomUUID) {
const file = join(os.homedir(), ".observablehq");
if (!_config) {
try {
_config = JSON.parse(await readFile(file, "utf8"));
} catch (e) {
// fall through
}
_config ??= {};
}
if (!_config[name]) {
_config[name] = generator();
await writeFile(file, JSON.stringify(_config, null, 2));
}
return _config[name];
}

type TelemetryEffects = {
env: NodeJS.ProcessEnv;
logger: Logger;
getPersistentId: typeof getPersistentId;
};
const defaultEffects: TelemetryEffects = {
env: process.env,
logger: console,
getPersistentId
};

export class Telemetry {
private disabled: boolean;
private debug: boolean;
private origin: string;
private logger: Logger;
private getPersistentId: typeof getPersistentId;
private timeZoneOffset = new Date().getTimezoneOffset();
private readonly pending = new Set<Promise<any>>();
private _ids: Promise<TelemetryIds> | undefined;
private _environment: Promise<TelemetryEnvironment> | undefined;

constructor(effects = defaultEffects) {
this.disabled = !!effects.env.OBSERVABLE_TELEMETRY_DISABLE;
this.debug = !!effects.env.OBSERVABLE_TELEMETRY_DEBUG;
this.origin = effects.env.OBSERVABLE_TELEMETRY_ORIGIN || "https://events.observablehq.com";
visnup marked this conversation as resolved.
Show resolved Hide resolved
this.logger = effects.logger;
this.getPersistentId = effects.getPersistentId;
}

async record(data: TelemetryData) {
if (this.disabled) return;
const task = (async () =>
this.send({
ids: await this.ids,
environment: await this.environment,
time: {now: performance.now(), timeOrigin: performance.timeOrigin, timeZoneOffset: this.timeZoneOffset},
mythmon marked this conversation as resolved.
Show resolved Hide resolved
data
})
.catch(() => {})
.finally(() => {
this.pending.delete(task);
}))();
this.pending.add(task);
}

flush() {
return Promise.all(this.pending);
}

private async getProjectId() {
const remote: string | null = await new Promise((resolve) => {
exec("git config --local --get remote.origin.url", (error, stdout) => resolve(error ? null : stdout.trim()));
});
const hash = createHash("sha256");
hash.update(await this.getPersistentId("cli_telemetry_salt"));
hash.update(remote || process.env.REPOSITORY_URL || process.cwd());
return hash.digest("base64");
}

private get ids() {
return (this._ids ??= Promise.all([this.getPersistentId("cli_telemetry_device"), this.getProjectId()]).then(
([device, project]) => ({
device,
project,
session: randomUUID()
})
));
}

private get environment() {
return (this._environment ??= Promise.all([
visnup marked this conversation as resolved.
Show resolved Hide resolved
import("../package.json"),
import("ci-info"),
import("is-docker"),
import("is-wsl")
]).then(([{default: pkg}, ci, {default: isDocker}, {default: isWSL}]) => {
const cpus = os.cpus() || [];
return {
version: pkg.version,
systemPlatform: os.platform(),
systemRelease: os.release(),
systemArchitecture: os.arch(),
cpuCount: cpus.length,
cpuModel: cpus.length ? cpus[0].model : null,
cpuSpeed: cpus.length ? cpus[0].speed : null,
memoryInMb: Math.trunc(os.totalmem() / Math.pow(1024, 2)),
isCI: ci.name || ci.isCI,
isDocker: isDocker(),
isWSL
};
}));
}

private async needsBanner() {
let called;
await this.getPersistentId("cli_telemetry_banner", () => (called = randomUUID()));
return !!called;
}

private async send(data: {
ids: TelemetryIds;
environment: TelemetryEnvironment;
time: TelemetryTime;
data: TelemetryData;
}): Promise<void> {
if (await this.needsBanner()) {
this.logger.error(
visnup marked this conversation as resolved.
Show resolved Hide resolved
`${magenta("Attention")}: Observable CLI collect anonymous telemetry data.\nSee ${cyan(
"https://observablehq.com/cli-telemetry"
)} for details and how to opt-out.`
);
}
if (this.debug) {
this.logger.error("[telemetry]", data);
return;
}
await fetch(`${this.origin}/cli`, {
method: "POST",
body: JSON.stringify(data),
headers: {"content-type": "application/json"}
});
}
}
8 changes: 6 additions & 2 deletions test/config-test.ts
Original file line number Diff line number Diff line change
@@ -1,7 +1,9 @@
import assert from "node:assert";
import {normalizeConfig as config, mergeToc, readConfig} from "../src/config.js";
import {Telemetry} from "../src/telemetry.js";

const root = "test/input/build/config";
const telemetry = new Telemetry();

describe("readConfig(undefined, root)", () => {
it("imports the config file at the specified root", async () => {
Expand All @@ -22,7 +24,8 @@ describe("readConfig(undefined, root)", () => {
deploy: {
workspace: "acme",
project: "bi"
}
},
telemetry
});
});
it("returns the default config if no config file is found", async () => {
Expand All @@ -35,7 +38,8 @@ describe("readConfig(undefined, root)", () => {
toc: {label: "Contents", show: true},
pager: true,
footer: 'Built with <a href="https://observablehq.com/" target=_blank>Observable</a>',
deploy: null
deploy: null,
telemetry
});
});
});
Expand Down
68 changes: 68 additions & 0 deletions test/telemetry-test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,68 @@
import assert from "assert";
import {randomUUID} from "crypto";
import {MockAgent, getGlobalDispatcher, setGlobalDispatcher} from "undici";
import {Telemetry} from "../src/telemetry.js";
import {MockLogger} from "./mocks/logger.js";

describe("telemetry", () => {
const globalDispatcher = getGlobalDispatcher();
let agent;

beforeEach(() => {
agent = new MockAgent();
agent.disableNetConnect();
agent.get("https://events.observablehq.com").intercept({path: "/cli", method: "POST"}).reply(204);
setGlobalDispatcher(agent);
});
afterEach(() => {
setGlobalDispatcher(globalDispatcher);
});

const noopEffects = {env: {}, logger: new MockLogger(), getPersistentId: async () => randomUUID()};

it("sends data", async () => {
const telemetry = new Telemetry(noopEffects);
telemetry.record({event: "build", step: "start", test: true});
await telemetry.flush();
agent.assertNoPendingInterceptors();
});

it("shows a banner", async () => {
const logger = new MockLogger();
const telemetry = new Telemetry({
...noopEffects,
logger,
getPersistentId: async (name, generator = randomUUID) => generator()
});
telemetry.record({event: "build", step: "start", test: true});
await telemetry.flush();
logger.assertExactErrors([/Attention.*telemetry.*https:\/\/observablehq.com/s]);
});

it("can be disabled", async () => {
const telemetry = new Telemetry({...noopEffects, env: {OBSERVABLE_TELEMETRY_DISABLE: "1"}});
telemetry.record({event: "build", step: "start", test: true});
await telemetry.flush();
assert.equal(agent.pendingInterceptors().length, 1);
});

it("debug prints data and disables", async () => {
const logger = new MockLogger();
const telemetry = new Telemetry({...noopEffects, env: {OBSERVABLE_TELEMETRY_DEBUG: "1"}, logger});
telemetry.record({event: "build", step: "start", test: true});
await telemetry.flush();
assert.equal(logger.errorLines.length, 1);
assert.equal(logger.errorLines[0][0], "[telemetry]");
assert.equal(agent.pendingInterceptors().length, 1);
});

it("silent on error", async () => {
const logger = new MockLogger();
agent.get("https://localhost").intercept({path: "/cli", method: "POST"}).replyWithError(new Error("silent"));
const telemetry = new Telemetry({...noopEffects, env: {OBSERVABLE_TELEMETRY_ORIGIN: "https://localhost"}, logger});
telemetry.record({event: "build", step: "start", test: true});
await telemetry.flush();
assert.equal(logger.errorLines.length, 0);
assert.equal(agent.pendingInterceptors().length, 1);
});
});
12 changes: 12 additions & 0 deletions yarn.lock
Original file line number Diff line number Diff line change
Expand Up @@ -985,6 +985,11 @@ [email protected]:
optionalDependencies:
fsevents "~2.3.2"

ci-info@^4.0.0:
version "4.0.0"
resolved "https://registry.yarnpkg.com/ci-info/-/ci-info-4.0.0.tgz#65466f8b280fc019b9f50a5388115d17a63a44f2"
integrity sha512-TdHqgGf9odd8SXNuxtUBVx8Nv+qZOejE6qyqiy5NtbYYQOeFa6zmHkxlPzmaLxWWHsU6nJmB7AETdVPi+2NBUg==

cliui@^7.0.2:
version "7.0.4"
resolved "https://registry.yarnpkg.com/cliui/-/cliui-7.0.4.tgz#a0265ee655476fc807aea9df3df8df7783808b4f"
Expand Down Expand Up @@ -2298,6 +2303,13 @@ is-wsl@^2.2.0:
dependencies:
is-docker "^2.0.0"

is-wsl@^3.1.0:
version "3.1.0"
resolved "https://registry.yarnpkg.com/is-wsl/-/is-wsl-3.1.0.tgz#e1c657e39c10090afcbedec61720f6b924c3cbd2"
integrity sha512-UcVfVfaK4Sc4m7X3dUSoHoozQGBEFeDC+zVo06t98xe8CzHSZZBekNXH+tu0NalHolcJ/QAGqS46Hef7QXBIMw==
dependencies:
is-inside-container "^1.0.0"

isarray@^2.0.5:
version "2.0.5"
resolved "https://registry.yarnpkg.com/isarray/-/isarray-2.0.5.tgz#8af1e4c1221244cc62459faf38940d4e644a5723"
Expand Down