commit c1ff9ee63effdd8af9aea594abf28f996b35e034 Author: JOLIMAITRE Matthieu Date: Mon Jun 3 03:07:55 2024 +0200 init diff --git a/README.md b/README.md new file mode 100644 index 0000000..106f95f --- /dev/null +++ b/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(); +``` \ No newline at end of file diff --git a/data/generate.ts b/data/generate.ts new file mode 100755 index 0000000..540f312 --- /dev/null +++ b/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(); diff --git a/data/generated.ts b/data/generated.ts new file mode 100644 index 0000000..2f32f94 --- /dev/null +++ b/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(); + } + + 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(); +`; \ No newline at end of file diff --git a/deno.json b/deno.json new file mode 100644 index 0000000..92b61b1 --- /dev/null +++ b/deno.json @@ -0,0 +1,6 @@ +{ + "fmt": { + "useTabs": true, + "lineWidth": 120 + } +} diff --git a/deno.lock b/deno.lock new file mode 100644 index 0000000..609bb9d --- /dev/null +++ b/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" + } +} diff --git a/example/simple.ts b/example/simple.ts new file mode 100755 index 0000000..86f45cd --- /dev/null +++ b/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(); + + 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(); diff --git a/mod.ts b/mod.ts new file mode 100644 index 0000000..8f7c8a1 --- /dev/null +++ b/mod.ts @@ -0,0 +1 @@ +export * from "./src/lib.ts"; diff --git a/src/child.ts b/src/child.ts new file mode 100644 index 0000000..ad8356d --- /dev/null +++ b/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(); + } + + 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(); diff --git a/src/lib.ts b/src/lib.ts new file mode 100644 index 0000000..5e15a91 --- /dev/null +++ b/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(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); + }); +} diff --git a/src/lib/observer.ts b/src/lib/observer.ts new file mode 100644 index 0000000..601035f --- /dev/null +++ b/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); + } +} diff --git a/src/lib/types.ts b/src/lib/types.ts new file mode 100644 index 0000000..ed7d810 --- /dev/null +++ b/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; diff --git a/src/lib/utils.ts b/src/lib/utils.ts new file mode 100644 index 0000000..eda3123 --- /dev/null +++ b/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 = (value: T) => void; + +export function split_promise() { + let resovler = null as Consumer | null; + const promise = new Promise((res) => resovler = res); + assertExists(resovler); + return [promise, resovler] as const; +} + +export class Lock { + private value; + private waiting_queue; + private in_use; + + public constructor(value: T) { + this.value = value; + this.waiting_queue = [] as Consumer[]; + this.in_use = new Ref(false); + } + + public async with(procedure: (guard: Guard) => Promise) { + 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(); + 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 { + private value; + private waiting_queue; + private in_use; + + constructor( + value: T, + waiting_queue: Consumer[], + in_use: Ref, + ) { + 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 { + public value; + + public constructor(value: T) { + this.value = value; + } +}