init

README.md

@@ -0,0 +1,33 @@
+# Profiterole
+
+Delicious profiling.
+
+## Description
+
+Profiterole is a framework for profiling Typescript sections in Deno scripts.
+
+## Usage
+
+```ts
+// note : needs --unstable-temporal
+// note : needs env variable PROFILE=true
+
+import { report, section, startup, tip, top } from "./mod.ts";
+
+async function main() {
+	await startup(); // note : prevents cold start of the framework.
+
+    for (const b of data) {
+        tip("iteration"); // note : with tip/top
+
+        const result = a + b;
+        section("serialize", () => JSON.stringify({ a, b })); // note : with section
+        
+        top("iteration");
+    }
+
+	report();
+}
+
+if (import.meta.main) await main();
+```

data/generate.ts

@@ -0,0 +1,20 @@
+#!/usr/bin/env -S deno run --allow-read --allow-write
+
+import { project_root } from "../src/lib/utils.ts";
+
+// note : useful for watch
+import {} from "../src/child.ts";
+
+async function main() {
+	const input_path = `${await project_root()}/src/child.ts`;
+	const content = await Deno.readTextFile(input_path);
+	const escaped = content
+		.replaceAll("\\", "\\\\")
+		.replaceAll("$", "\\$")
+		.replaceAll("`", "\\`");
+	const src = `export const program = \`${escaped}\`;`;
+	const output_path = `${await project_root()}/data/generated.ts`;
+	await Deno.writeTextFile(output_path, src);
+}
+
+if (import.meta.main) await main();

data/generated.ts

@@ -0,0 +1,86 @@
+export const program = `import { TextLineStream } from "https://deno.land/std@0.224.0/streams/text_line_stream.ts";
+import type { Msg } from "./lib/types.ts";
+
+async function main() {
+	const [sokcet_path] = Deno.args;
+	if (sokcet_path === undefined) throw new Error("Feur.");
+
+	const socket = Deno.listen({ transport: "unix", path: sokcet_path });
+	const connection = await socket.accept();
+	const lines = connection.readable
+		.pipeThrough(new TextDecoderStream())
+		.pipeThrough(new TextLineStream());
+
+	const stats = new Tracker();
+	try {
+		for await (const line of lines) stats.update(JSON.parse(line) as Msg);
+	} catch (_) { /* STDOUT closed */ }
+
+	stats.log();
+}
+
+class Tracker {
+	register;
+
+	constructor() {
+		this.register = new Map<string, SectionTracker>();
+	}
+
+	update(message: Msg) {
+		if (message[0] === 0) this.get_tracker_for(message[1]).tip(message[2]);
+		if (message[0] === 1) this.get_tracker_for(message[1]).top(message[2]);
+		if (message[0] === 2) this.log();
+	}
+
+	get_tracker_for(section: string) {
+		const stored = this.register.get(section);
+		if (stored !== undefined) return stored;
+		const new_ = new SectionTracker(section);
+		this.register.set(section, new_);
+		return new_;
+	}
+
+	log() {
+		for (const section of this.register.values()) section.log();
+		Deno.exit(0);
+	}
+}
+
+class SectionTracker {
+	name;
+	runs;
+	current_tip;
+
+	constructor(name: string) {
+		this.name = name;
+		this.runs = [] as number[];
+		this.current_tip = null as number | null;
+	}
+
+	tip(timestamp_ns: number) {
+		if (this.current_tip !== null) throw new Error(\`Second TIP before TOP on section \${this.name}.\`);
+		this.current_tip = timestamp_ns;
+	}
+
+	top(timestamp_ns: number) {
+		if (this.current_tip === null) throw new Error(\`TOP before TIP on section \${this.name}.\`);
+		const duration = timestamp_ns - this.current_tip;
+		this.current_tip = null;
+		this.runs.push(duration);
+	}
+
+	log() {
+		const count = this.runs.length;
+		const avg = this.average() / 1_000;
+		const line = \`\${this.name} :\\t\${count} runs, \${avg} µs avg\`;
+		console.log(line);
+	}
+
+	average() {
+		const total = this.runs.reduce((a, b) => a + b);
+		return total / this.runs.length;
+	}
+}
+
+if (import.meta.main) await main();
+`;

deno.json

@@ -0,0 +1,6 @@
+{
+	"fmt": {
+		"useTabs": true,
+		"lineWidth": 120
+	}
+}

deno.lock

@@ -0,0 +1,25 @@
+{
+  "version": "3",
+  "redirects": {
+    "https://deno.land/x/Thread": "https://deno.land/x/Thread@v4.2.0",
+    "https://deno.land/x/Thread/Thread.ts": "https://deno.land/x/Thread@v4.2.0/Thread.ts"
+  },
+  "remote": {
+    "https://deno.land/std@0.224.0/assert/assert_exists.ts": "43420cf7f956748ae6ed1230646567b3593cb7a36c5a5327269279c870c5ddfd",
+    "https://deno.land/std@0.224.0/assert/assertion_error.ts": "ba8752bd27ebc51f723702fac2f54d3e94447598f54264a6653d6413738a8917",
+    "https://deno.land/std@0.224.0/fs/exists.ts": "3d38cb7dcbca3cf313be343a7b8af18a87bddb4b5ca1bd2314be12d06533b50f",
+    "https://deno.land/std@0.224.0/io/write_all.ts": "24aac2312bb21096ae3ae0b102b22c26164d3249dff96dbac130958aa736f038",
+    "https://deno.land/std@0.224.0/path/_common/assert_path.ts": "dbdd757a465b690b2cc72fc5fb7698c51507dec6bfafce4ca500c46b76ff7bd8",
+    "https://deno.land/std@0.224.0/path/_common/constants.ts": "dc5f8057159f4b48cd304eb3027e42f1148cf4df1fb4240774d3492b5d12ac0c",
+    "https://deno.land/std@0.224.0/path/_common/dirname.ts": "684df4aa71a04bbcc346c692c8485594fc8a90b9408dfbc26ff32cf3e0c98cc8",
+    "https://deno.land/std@0.224.0/path/_common/strip_trailing_separators.ts": "7024a93447efcdcfeaa9339a98fa63ef9d53de363f1fbe9858970f1bba02655a",
+    "https://deno.land/std@0.224.0/path/_os.ts": "8fb9b90fb6b753bd8c77cfd8a33c2ff6c5f5bc185f50de8ca4ac6a05710b2c15",
+    "https://deno.land/std@0.224.0/path/dirname.ts": "85bd955bf31d62c9aafdd7ff561c4b5fb587d11a9a5a45e2b01aedffa4238a7c",
+    "https://deno.land/std@0.224.0/path/posix/_util.ts": "1e3937da30f080bfc99fe45d7ed23c47dd8585c5e473b2d771380d3a6937cf9d",
+    "https://deno.land/std@0.224.0/path/posix/dirname.ts": "76cd348ffe92345711409f88d4d8561d8645353ac215c8e9c80140069bf42f00",
+    "https://deno.land/std@0.224.0/path/windows/_util.ts": "d5f47363e5293fced22c984550d5e70e98e266cc3f31769e1710511803d04808",
+    "https://deno.land/std@0.224.0/path/windows/dirname.ts": "33e421be5a5558a1346a48e74c330b8e560be7424ed7684ea03c12c21b627bc9",
+    "https://deno.land/std@0.224.0/streams/text_line_stream.ts": "21f33d3922e019ec1a1676474beb543929cb564ec99b69cd2654e029e0f45bd5",
+    "https://deno.land/x/Thread@v4.2.0/Thread.ts": "33d9c98a87cb444ddb1f5dc046ed51183d7b07570e41040dcd2eb63492d158c3"
+  }
+}

example/simple.ts

@@ -0,0 +1,32 @@
+#!/usr/bin/env -S deno run -A --unstable-temporal
+Deno.env.set("PROFILE", "true");
+
+import { report, section, startup, tip, top } from "../mod.ts";
+import { range } from "../src/lib/utils.ts";
+
+async function main() {
+	await startup();
+	console.log("Starting ...");
+
+	const data = Array.from(range(0, 100));
+	const results = new Map<string, number>();
+
+	for (const a of data) {
+		// with tip/top
+		tip("table_of_it");
+		for (const b of data) {
+			tip("iteration");
+			const result = a + b;
+			// with section
+			const key = section("serialize", () => JSON.stringify({ a, b }));
+			section("insertion", () => results.set(key, result));
+			top("iteration");
+		}
+		top("table_of_it");
+	}
+
+	console.log("Done.");
+	report();
+}
+
+if (import.meta.main) await main();

mod.ts

@@ -0,0 +1 @@
+export * from "./src/lib.ts";

src/child.ts

@@ -0,0 +1,85 @@
+import { TextLineStream } from "https://deno.land/std@0.224.0/streams/text_line_stream.ts";
+import type { Msg } from "./lib/types.ts";
+
+async function main() {
+	const [sokcet_path] = Deno.args;
+	if (sokcet_path === undefined) throw new Error("Feur.");
+
+	const socket = Deno.listen({ transport: "unix", path: sokcet_path });
+	const connection = await socket.accept();
+	const lines = connection.readable
+		.pipeThrough(new TextDecoderStream())
+		.pipeThrough(new TextLineStream());
+
+	const stats = new Tracker();
+	try {
+		for await (const line of lines) stats.update(JSON.parse(line) as Msg);
+	} catch (_) { /* STDOUT closed */ }
+
+	stats.log();
+}
+
+class Tracker {
+	register;
+
+	constructor() {
+		this.register = new Map<string, SectionTracker>();
+	}
+
+	update(message: Msg) {
+		if (message[0] === 0) this.get_tracker_for(message[1]).tip(message[2]);
+		if (message[0] === 1) this.get_tracker_for(message[1]).top(message[2]);
+		if (message[0] === 2) this.log();
+	}
+
+	get_tracker_for(section: string) {
+		const stored = this.register.get(section);
+		if (stored !== undefined) return stored;
+		const new_ = new SectionTracker(section);
+		this.register.set(section, new_);
+		return new_;
+	}
+
+	log() {
+		for (const section of this.register.values()) section.log();
+		Deno.exit(0);
+	}
+}
+
+class SectionTracker {
+	name;
+	runs;
+	current_tip;
+
+	constructor(name: string) {
+		this.name = name;
+		this.runs = [] as number[];
+		this.current_tip = null as number | null;
+	}
+
+	tip(timestamp_ns: number) {
+		if (this.current_tip !== null) throw new Error(`Second TIP before TOP on section ${this.name}.`);
+		this.current_tip = timestamp_ns;
+	}
+
+	top(timestamp_ns: number) {
+		if (this.current_tip === null) throw new Error(`TOP before TIP on section ${this.name}.`);
+		const duration = timestamp_ns - this.current_tip;
+		this.current_tip = null;
+		this.runs.push(duration);
+	}
+
+	log() {
+		const count = this.runs.length;
+		const avg = this.average() / 1_000;
+		const line = `${this.name} :\t${count} runs, ${avg} µs avg`;
+		console.log(line);
+	}
+
+	average() {
+		const total = this.runs.reduce((a, b) => a + b);
+		return total / this.runs.length;
+	}
+}
+
+if (import.meta.main) await main();

src/lib.ts

@@ -0,0 +1,46 @@
+import { Observer, Sender } from "./lib/observer.ts";
+import { Lock, Ref } from "./lib/utils.ts";
+
+const enabled = Deno.env.get("PROFILE") === "true";
+
+export async function startup() {
+	if (!enabled) return;
+	await with_(() => {});
+}
+
+export function tip(name: string) {
+	if (!enabled) return;
+	const now = Temporal.Now.instant();
+	with_((sender) => sender.tip(name, Number(now.epochNanoseconds)));
+}
+
+export function top(name: string) {
+	if (!enabled) return;
+	const now = Temporal.Now.instant();
+	with_((sender) => sender.top(name, Number(now.epochNanoseconds)));
+}
+
+export function section<T>(name: string, procedure: () => T): T {
+	tip(name);
+	const result = procedure();
+	if (result instanceof Promise) return result.finally(() => top(name)) as unknown as T;
+	else top(name);
+	return result;
+}
+
+export async function report() {
+	if (!enabled) return;
+	await with_((sender) => sender.log());
+}
+
+const sender = new Lock(new Ref(null as Sender | null));
+async function with_(procedure: (sender: Sender) => unknown) {
+	return await sender.with(async (guard) => {
+		const ref = guard.get();
+		if (ref.value === null) {
+			const observer = await Observer.spawn();
+			ref.value = new Sender(observer);
+		}
+		return await procedure(ref.value);
+	});
+}

src/lib/observer.ts

@@ -0,0 +1,65 @@
+import { program } from "../../data/generated.ts";
+import { wait_file } from "./utils.ts";
+import { Msg } from "./types.ts";
+import { writeAll } from "https://deno.land/std@0.224.0/io/write_all.ts";
+
+export class Sender {
+	observer;
+
+	constructor(observer: Observer) {
+		this.observer = observer;
+	}
+
+	tip(section: string, timestamp_ns: number) {
+		this.observer.send([0, section, timestamp_ns]);
+	}
+
+	top(section: string, timestamp_ns: number) {
+		this.observer.send([1, section, timestamp_ns]);
+	}
+
+	log() {
+		this.observer.send([2]);
+	}
+}
+
+export class Observer {
+	process;
+	socket;
+
+	constructor(process: Deno.ChildProcess, socket: Deno.UnixConn) {
+		this.process = process;
+		this.socket = socket;
+	}
+
+	static async spawn() {
+		const socket_path = `/tmp/profiterole-${Date.now()}.sock`;
+		const args = [
+			"run",
+			`--allow-read=${socket_path}`,
+			`--allow-write=${socket_path}`,
+			"-",
+			socket_path,
+		];
+		const process = new Deno.Command("deno", { args, stdin: "piped" }).spawn();
+		const encoded = new TextEncoder().encode(program);
+		const writer = process.stdin.getWriter();
+		await writer.write(encoded);
+		await writer.close();
+		await writer.closed;
+		// process.unref();
+		// TODO : figure a way to have the child process survive after death of parent process.
+		//        then detects parent process is dead and log automatically.
+
+		await wait_file(socket_path);
+
+		const socket = await Deno.connect({ transport: "unix", path: socket_path });
+		socket.unref();
+		return new Observer(process, socket);
+	}
+
+	async send(message: Msg) {
+		const encoded = new TextEncoder().encode(JSON.stringify(message) + "\n");
+		await writeAll(this.socket, encoded);
+	}
+}

src/lib/types.ts

@@ -0,0 +1,4 @@
+export type TipMsg = [0, name: string, timestamp_ns: number];
+export type TopMsg = [1, name: string, timestamp_ns: number];
+export type LogMsg = [2];
+export type Msg = TipMsg | TopMsg | LogMsg;

src/lib/utils.ts

@@ -0,0 +1,96 @@
+import { dirname } from "https://deno.land/std@0.224.0/path/dirname.ts";
+import { exists } from "https://deno.land/std@0.224.0/fs/exists.ts";
+import { assertExists } from "https://deno.land/std@0.224.0/assert/assert_exists.ts";
+
+export function* range(from: number, to: number) {
+	while (from < to) yield from++;
+}
+
+export async function project_root() {
+	const this_url = new URL(import.meta.url);
+	const this_abs_path = await Deno.realPath(this_url.pathname);
+	return dirname(dirname(dirname(this_abs_path)));
+}
+
+export async function wait(ms: number) {
+	await new Promise((res) => setTimeout(res, ms));
+}
+
+export async function wait_file(path: string, delay_ms: number = 10) {
+	while (true) {
+		if (await exists(path)) return;
+		await wait(delay_ms);
+	}
+}
+
+export type Consumer<T> = (value: T) => void;
+
+export function split_promise<T>() {
+	let resovler = null as Consumer<T> | null;
+	const promise = new Promise<T>((res) => resovler = res);
+	assertExists(resovler);
+	return [promise, resovler] as const;
+}
+
+export class Lock<T> {
+	private value;
+	private waiting_queue;
+	private in_use;
+
+	public constructor(value: T) {
+		this.value = value;
+		this.waiting_queue = [] as Consumer<void>[];
+		this.in_use = new Ref(false);
+	}
+
+	public async with<O>(procedure: (guard: Guard<T>) => Promise<O>) {
+		const guard = await this.lock();
+		const result = await procedure(guard);
+		guard.release();
+		return result;
+	}
+
+	public async lock() {
+		if (this.in_use.value) {
+			const [promise, consumer] = split_promise<void>();
+			this.waiting_queue.push(consumer);
+			await promise;
+		}
+		this.in_use.value = true;
+		return new Guard(this.value, this.waiting_queue, this.in_use);
+	}
+}
+
+export class Guard<T> {
+	private value;
+	private waiting_queue;
+	private in_use;
+
+	constructor(
+		value: T,
+		waiting_queue: Consumer<void>[],
+		in_use: Ref<boolean>,
+	) {
+		this.value = value;
+		this.waiting_queue = waiting_queue;
+		this.in_use = in_use;
+	}
+
+	public release() {
+		this.in_use.value = false;
+		const [first] = this.waiting_queue.splice(0, 1);
+		if (first !== undefined) first();
+	}
+
+	public get() {
+		return this.value;
+	}
+}
+
+export class Ref<T> {
+	public value;
+
+	public constructor(value: T) {
+		this.value = value;
+	}
+}