Skip to content

Commit

Permalink
Instrument Deno.Command() - replaces Deno.run()
Browse files Browse the repository at this point in the history
Better late than never
  • Loading branch information
danopia committed May 18, 2024
1 parent ea0e851 commit 0eb6d1a
Show file tree
Hide file tree
Showing 3 changed files with 205 additions and 31 deletions.
84 changes: 55 additions & 29 deletions demo.ts
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
#!/usr/bin/env -S deno run --watch --allow-read --allow-sys=hostname,osRelease --allow-env --allow-net --allow-run=uptime,sleep,ping
#!/usr/bin/env -S deno run --watch --allow-read --allow-sys=hostname,osRelease --allow-env --allow-net --allow-run=uptime,sleep,ping,nonextant
import { metrics, trace, ValueType } from "./opentelemetry/api.js";
import { logs } from "./opentelemetry/api-logs.js";
import { SEMATTRS_HTTP_METHOD } from "./opentelemetry/semantic-conventions.js";
Expand Down Expand Up @@ -33,10 +33,12 @@ async function handler(req: Request): Promise<Response> {
test3.add(1, {[SEMATTRS_HTTP_METHOD]: req.method});
test2.record(50+Math.round(Math.random()*25), {[SEMATTRS_HTTP_METHOD]: req.method});

logger.emit({
body: 'hello world',
});

if (url.pathname == '/log') {
logger.emit({
body: 'hello world',
});
return new Response('logged hello world');
}

if (url.pathname == '/inner') {
await getData();
Expand All @@ -48,49 +50,73 @@ async function handler(req: Request): Promise<Response> {

if (url.pathname == '/uptime') {
const text = await new Promise<string>(ok => setTimeout(async () => {
const proc = Deno.run({
cmd: ['uptime'],
const proc = await new Deno.Command('uptime', {
stdin: 'null',
stdout: 'piped',
stderr: 'inherit',
});
const text = await new Response(proc.stdout.readable).text();
await proc.status();
}).output();
const text = new TextDecoder().decode(proc.stdout);
ok(text);
}, 50));
return new Response(text);
}

if (url.pathname == '/failure') {
try {
await new Deno.Command('nonextant', {
stdin: 'null',
stdout: 'piped',
stderr: 'inherit',
}).output();
return new Response('No failure happened??');
} catch (err) {
return new Response(`Failed as expected.\n${err.message}`);
}
}

if (url.pathname == '/sleep') {
const proc = Deno.run({
cmd: ['sleep', '1'],

// First, we spawn and gather the output as two chained steps.
await new Deno.Command('sleep', {
args: ['1'],
stdin: 'null',
});
await proc.status();
await Promise.all([1,2,3,4,5].map(x => {
const proc = Deno.run({
cmd: ['sleep', `${x}`],
}).spawn().output();

// Second, we spawn and gather the output as two different steps on the Command.
{
const sleepCmd = new Deno.Command('sleep', {
args: ['1'],
stdin: 'null',
});
return proc.status();
}));
const proc2 = Deno.run({
cmd: ['sleep', '1'],
sleepCmd.spawn();
await sleepCmd.output();
}

// Third, we run command in parallel, using the single-shot output() API.
await Promise.all([1,2,3,4,5].map(x =>
new Deno.Command('sleep', {
args: [`${x}`],
stdin: 'null',
}).output()));

// Fourth, we run the command with the synchronous single-shot API.
// This is not ideal in a server but we need to make sure our instrument works regardless.
new Deno.Command('sleep', {
args: ['1'],
stdin: 'null',
});
await proc2.status();
return new Response('done');
}).outputSync();

return new Response('done sleeping');
}

if (url.pathname == '/ping') {
const proc = Deno.run({
cmd: ['ping', '-c5', 'google.com'],
const proc = new Deno.Command('ping', {
args: ['-c5', 'google.com'],
stdin: 'null',
stdout: 'piped',
stderr: 'inherit',
});
proc.status();
return new Response(proc.stdout.readable);
}).spawn();
return new Response(proc.stdout);
}

if (url.pathname == '/') {
Expand Down
6 changes: 4 additions & 2 deletions instrumentation/auto.ts
Original file line number Diff line number Diff line change
@@ -1,9 +1,10 @@
import { InstrumentationBase } from "../opentelemetry/instrumentation.js";

import { DenoCommandInstrumentation } from "./deno-command.ts";
import { DenoKvInstrumentation } from "./deno-kv.ts";
import { DenoRunInstrumentation } from "./deno-run.ts";
import { DenoRuntimeInstrumentation } from "./deno-runtime.ts";
import { FetchInstrumentation } from "./fetch.ts";
import { DenoRunInstrumentation } from "./deno-run.ts";
import { DenoKvInstrumentation } from "./deno-kv.ts";

export function getDenoAutoInstrumentations() {
const instrs: InstrumentationBase[] = [
Expand All @@ -12,6 +13,7 @@ export function getDenoAutoInstrumentations() {

// Rough check to exclude Deno Deploy, which doesn't have subprocesses etc.
if (Deno.version?.deno) {
instrs.push(new DenoCommandInstrumentation());
instrs.push(new DenoRunInstrumentation());
instrs.push(new DenoRuntimeInstrumentation());
}
Expand Down
146 changes: 146 additions & 0 deletions instrumentation/deno-command.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,146 @@
import { type Span, SpanStatusCode } from "../opentelemetry/api.js";
import type { Attributes } from "../opentelemetry/api.js";
import {
isWrapped,
InstrumentationBase,
type InstrumentationConfig,
} from "../opentelemetry/instrumentation.js";

function wrapChildPromise<T extends Deno.CommandStatus>(span: Span, promise: Promise<T>) {
return promise.then(status => {
recordChildExit(span, status);
return status;
}, err => {
recordChildFailed(span, err as Error)
return Promise.reject(err);
});
}
function recordChildExit(span: Span, output: Deno.CommandStatus) {
span.setAttribute('exec.success', output.success);
span.setAttribute('exec.exit_code', output.code);
if (output.signal) {
span.setAttribute('exec.signal', output.signal);
}
span.setStatus({
code: SpanStatusCode.OK,
});
}
function recordSpawnFailed(span: Span, err: Error) {
// This is hit when the requested program doesn't exist, for example
span.recordException(err);
span.setStatus({
code: SpanStatusCode.ERROR,
message: 'Failed to launch subprocess',
});
}
function recordChildFailed(span: Span, err: Error) {
// I'm not sure what situation hits this.
span.recordException(err);
span.setStatus({
code: SpanStatusCode.ERROR,
message: `Subprocess failed: ${err.message}`,
});
}

export class DenoCommandInstrumentation extends InstrumentationBase {
readonly component: string = 'Deno.Command';
moduleName = this.component;

constructor(config?: InstrumentationConfig) {
super('Deno.Command', '0.1.0', config);
}

init(): void {}

/**
* Patches the constructor of Command
*/
private _patchConstructor(): (original: typeof Deno.Command) => typeof Deno.Command {
// deno-lint-ignore no-this-alias
const plugin = this;

// We need to capture the arguments to the constructor, and also override the methods
// Let's see if subclassing will get us close enough without causing other issues
return original => class InstrumentedCommand extends original {
constructor(program: string | URL, opts: Deno.CommandOptions) {
super(program, opts);

this._spanName = `exec: ${program.toString().split('/').at(-1)}`;
this._attributes = {
'exec.command': program.toString(),
'exec.arguments': opts.args?.map(x => x.toString()) ?? [],
// 'component': plugin.moduleName,
}
}
private readonly _spanName: string; // Maybe we can accept an attributes->string transformer?
private readonly _attributes: Attributes;
private _span: Span | null = null;

override output(): Promise<Deno.CommandOutput> {
// output() can be called after spawn() - we don't want to double-instrument in that case
if (this._span) return super.output();

const span = this._span ??= plugin.tracer.startSpan(this._spanName, this._attributes);
try {
return wrapChildPromise(span, super.output())
.finally(() => span.end());
} catch (err) {
// The child failed before making a promise.
recordSpawnFailed(span, err as Error);
span.end();
throw err;
}
}
outputSync(): Deno.CommandOutput {
const span = this._span ??= plugin.tracer.startSpan(this._spanName, this._attributes);
try {
const output = super.outputSync();
recordChildExit(span, output);
span.end();
return output;
} catch (err) {
// The child at some point, likely when spawning, we assume that.
recordSpawnFailed(span, err as Error);
span.end();
throw err;
}
}
spawn(): Deno.ChildProcess {
const span = this._span ??= plugin.tracer.startSpan(this._spanName, this._attributes);
try {
const process = super.spawn();
// We replace the promise so that the calling code can catch our pass-thru rejection
Object.defineProperty(process, 'status', {
writable: false,
value: wrapChildPromise(span, process.status)
.finally(() => span.end()),
});
return process;
} catch (err) {
// The child failed before making a promise.
recordSpawnFailed(span, err as Error);
span.end();
throw err;
}
}
};
}

/**
* implements enable function
*/
override enable(): void {
if (isWrapped(Deno.Command)) {
this._unwrap(Deno, 'Command');
this._diag.debug('removing previous patch for constructor');
}
this._wrap(Deno, 'Command', this._patchConstructor());
}

/**
* implements unpatch function
*/
override disable(): void {
this._unwrap(Deno, 'Command');
}
}

0 comments on commit 0eb6d1a

Please sign in to comment.