Skip to content

Commit

Permalink
runtime: map error position
Browse files Browse the repository at this point in the history
  • Loading branch information
josephjclark committed Dec 19, 2024
1 parent fba35fa commit 92ae3a2
Show file tree
Hide file tree
Showing 8 changed files with 185 additions and 46 deletions.
39 changes: 39 additions & 0 deletions packages/runtime/src/errors.ts
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,8 @@
// It would be nice for the detail to be in the error, not the code
// But that probably requires more detailed error types

import expression, { ExecuteBreak } from './execute/expression'

export function assertImportError(e: any) {
if (e.name === 'ImportError') {
throw e;
Expand Down Expand Up @@ -50,10 +52,28 @@ export function assertAdaptorError(e: any) {
}
}

// v8 only returns positional information as a string
// this function will pull the line/col information back out of it
export const extractCallSite = (e: RTError) => {
if (e.stack) {
debugger;
const [_message, frame1] = e.stack.split('\n');

// find the line:col at the end
// structures here https://nodejs.org/api/errors.html#errorstack
const parts = frame1.split(':');
e.pos = {
col: parseInt(parts.pop()!.replace(')', '')),
line: parseInt(parts.pop()!),
};
}
};

// Abstract error supertype
export class RTError extends Error {
source = 'runtime';
name: string = 'Error';
pos?: { col: number, line: number} = undefined;

constructor() {
super();
Expand Down Expand Up @@ -92,6 +112,13 @@ export class RuntimeError extends RTError {
super();
this.subtype = error.constructor.name;
this.message = `${this.subtype}: ${error.message}`;

// automatically limit the stacktrace (?)
// Error.captureStackTrace(this, expression);

// extract positional info for source mapping
extractCallSite(error);
this.pos = error.pos;
}
}

Expand All @@ -106,7 +133,19 @@ export class RuntimeCrash extends RTError {
constructor(error: Error) {
super();
this.subtype = error.constructor.name;
// this.type = error.type;
this.message = `${this.subtype}: ${error.message}`;
// this.stack = error.stack;

// automatically limit the stacktrace (?)
// console.log(ExecuteBreak)
// Error.captureStackTrace(error, ExecuteBreak);
// Error.captureStackTrace(error, undefined);
// Error.captureStackTrace(error, function(){});

// extract positional info for source mapping
extractCallSite(error);
this.pos = error.pos;
}
}

Expand Down
98 changes: 71 additions & 27 deletions packages/runtime/src/execute/expression.ts
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,8 @@ export type ExecutionErrorWrapper = {
error: any;
};



// TODO don't send the whole context because it's a bit confusing - just the options maybe?
export default (
ctx: ExecutionContext,
Expand All @@ -37,8 +39,8 @@ export default (
// allow custom linker options to be passed for this step
// this lets us use multiple versions of the same adaptor in a workflow
moduleOverrides?: ModuleInfoMap
) =>
new Promise(async (resolve, reject) => {
) => {
return new Promise(async (resolve, reject) => {
let duration = Date.now();
const { logger, plan, opts = {} } = ctx;
try {
Expand Down Expand Up @@ -85,6 +87,8 @@ export default (
// whatever initial state looks like now, clean it and report it back
duration = Date.now() - duration;
let finalError;
// Error.captureStackTrace(e, undefined);
// console.log(e)
try {
assertImportError(e);
assertRuntimeError(e);
Expand All @@ -98,7 +102,36 @@ export default (

reject({ state: input, error: finalError } as ExecutionErrorWrapper);
}
});
})
}

// This indirection lets us trap error stacks
export async function ExecuteBreak(context: any, state: State) {
const { fn, logger, name, immutableState } = context;

logger.debug(`Starting operation ${name}`);
const start = new Date().getTime();
if (isNullState(state)) {
clearNullState(state);
logger.warn(
`WARNING: No state was passed into operation ${name}. Did the previous operation return state?`
);
}
const newState = immutableState ? clone(state) : state;

let result = await fn(newState);

if (!result) {
logger.debug(`Warning: operation ${name} did not return state`);
result = createNullState();
}

// TODO should we warn if an operation does not return state?
// the trick is saying WHICH operation without source mapping
const duration = printDuration(new Date().getTime() - start);
logger.debug(`Operation ${name} complete in ${duration}`);
return result;
}

// Wrap an operation with various useful stuff
export const wrapOperation = (
Expand All @@ -107,32 +140,43 @@ export const wrapOperation = (
name: string,
immutableState?: boolean
) => {
return async (state: State) => {
logger.debug(`Starting operation ${name}`);
const start = new Date().getTime();
if (isNullState(state)) {
clearNullState(state);
logger.warn(
`WARNING: No state was passed into operation ${name}. Did the previous operation return state?`
);
}
const newState = immutableState ? clone(state) : state;

let result = await fn(newState);

if (!result) {
logger.debug(`Warning: operation ${name} did not return state`);
result = createNullState();
}

// TODO should we warn if an operation does not return state?
// the trick is saying WHICH operation without source mapping
const duration = printDuration(new Date().getTime() - start);
logger.debug(`Operation ${name} complete in ${duration}`);
return result;
};
const context = { fn, logger, name, immutableState };
return async (state: State) => ExecuteBreak(context, state)
};

// // Wrap an operation with various useful stuff
// export const wrapOperation = (
// fn: Operation,
// logger: Logger,
// name: string,
// immutableState?: boolean
// ) => {
// return async function ExecuteBreak(state: State) {
// logger.debug(`Starting operation ${name}`);
// const start = new Date().getTime();
// if (isNullState(state)) {
// clearNullState(state);
// logger.warn(
// `WARNING: No state was passed into operation ${name}. Did the previous operation return state?`
// );
// }
// const newState = immutableState ? clone(state) : state;

// let result = await fn(newState);

// if (!result) {
// logger.debug(`Warning: operation ${name} did not return state`);
// result = createNullState();
// }

// // TODO should we warn if an operation does not return state?
// // the trick is saying WHICH operation without source mapping
// const duration = printDuration(new Date().getTime() - start);
// logger.debug(`Operation ${name} complete in ${duration}`);
// return result;
// };
// };

export const mergeLinkerOptions = (
options: ModuleInfoMap = {},
overrides: ModuleInfoMap = {}
Expand Down
7 changes: 4 additions & 3 deletions packages/runtime/src/execute/plan.ts
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,7 @@ import type { Options } from '../runtime';
import validatePlan from '../util/validate-plan';
import createErrorReporter from '../util/log-error';
import { NOTIFY_STATE_LOAD } from '../events';
import { CompiledExecutionPlan } from '../types';
import { CompiledExecutionPlan, ExecutionContext } from '../types';

const executePlan = async (
plan: ExecutionPlan,
Expand All @@ -30,12 +30,13 @@ const executePlan = async (

const { workflow, options } = compiledPlan;

const ctx = {
const ctx: ExecutionContext = {
plan: compiledPlan,
opts,
logger,
report: createErrorReporter(logger),
notify: opts.callbacks?.notify ?? (() => {}),
sourceMap: opts.sourceMap
};

// Record of state on leaf nodes (nodes with no next)
Expand All @@ -44,7 +45,7 @@ const executePlan = async (
if (typeof input === 'string') {
const id = input;
const startTime = Date.now();
logger.debug(`fetching intial state ${id}`);
logger.debug(`fetching initial state ${id}`);

input = await opts.callbacks?.resolveState?.(id);
const duration = Date.now() - startTime;
Expand Down
12 changes: 10 additions & 2 deletions packages/runtime/src/execute/step.ts
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ import {
NOTIFY_JOB_START,
} from '../events';
import { isNullState } from '../util/null-state';
import getMappedPosition from '../util/get-mapped-position';

const loadCredentials = async (
job: Job,
Expand Down Expand Up @@ -165,9 +166,10 @@ const executeStep = async (
try {
// TODO include the upstream job?
notify(NOTIFY_JOB_START, { jobId });

debugger;
result = await executeExpression(ctx, job.expression, state, step.linker);
} catch (e: any) {
console.log(e);
didError = true;
if (e.hasOwnProperty('error') && e.hasOwnProperty('state')) {
const { error, state: errState } = e as ExecutionErrorWrapper;
Expand All @@ -177,13 +179,19 @@ const executeStep = async (
logger.error(`${jobName} aborted with error (${duration})`);

state = prepareFinalState(state, logger, ctx.opts.statePropsToRemove);
// Whatever the final state was, save that as the intial state to the next thing
// Whatever the final state was, save that as the initial state to the next thing
result = state;

if (error.pos && ctx.sourceMap) {
error.pos = await getMappedPosition(ctx.sourceMap, error.pos.line, error.pos.col)
}

report(state, jobId, error);

next = calculateNext(step, result, logger);


// TODO should we add positional information here?
notify(NOTIFY_JOB_ERROR, {
duration: Date.now() - startTime,
error,
Expand Down
5 changes: 1 addition & 4 deletions packages/runtime/src/runtime.ts
Original file line number Diff line number Diff line change
@@ -1,13 +1,10 @@
import { createMockLogger, Logger } from '@openfn/logger';
import type { ExecutionPlan, State } from '@openfn/lexicon';
import type { ExecutionCallbacks } from './types';
import type { ExecutionCallbacks, SourceMap } from './types';
import type { LinkerOptions } from './modules/linker';
import executePlan from './execute/plan';
import { defaultState, parseRegex, clone } from './util/index';

// TODO we should be able to get a proper typing for this from somewherewhere
type SourceMap = any;

export type Options = {
logger?: Logger;
jobLogger?: Logger;
Expand Down
4 changes: 4 additions & 0 deletions packages/runtime/src/types.ts
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,9 @@ import {
} from './events';
import { ModuleInfoMap } from './modules/linker';

// TODO we should be able to get a proper typing for this from somewhere
export type SourceMap = any;

export type CompiledEdge =
| boolean
| {
Expand Down Expand Up @@ -58,6 +61,7 @@ export type ExecutionContext = {
plan: CompiledExecutionPlan;
logger: Logger;
opts: Options;
sourceMap?: SourceMap
report: ErrorReporter;
notify: NotifyHandler;
};
Expand Down
5 changes: 3 additions & 2 deletions packages/runtime/src/util/get-mapped-position.ts
Original file line number Diff line number Diff line change
Expand Up @@ -5,14 +5,15 @@
import { SourceMapConsumer } from 'source-map';

const getMappedPosition = async (map, line, column) => {
debugger
const smc = await new SourceMapConsumer(map);
const pos = smc.originalPositionFor({
line,
column,
});

//return { line, col, src };
return pos;
return { line, col: pos.column/*, src*/ };
// return pos;
};

export default getMappedPosition;
Loading

0 comments on commit 92ae3a2

Please sign in to comment.