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

[FEATURE] Include hooks in time measurement of blocks #638

Merged
merged 1 commit into from
Jan 23, 2025
Merged
Show file tree
Hide file tree
Changes from all 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
57 changes: 42 additions & 15 deletions libs/execution/src/lib/blocks/block-execution-util.ts
Original file line number Diff line number Diff line change
Expand Up @@ -62,14 +62,11 @@ export async function executeBlocks(

executionContext.enterNode(block);

await executionContext.executeHooks(inputValue);

const executionResult = await executeBlock(
inputValue,
block,
executionContext,
);
await executionContext.executeHooks(inputValue, executionResult);

if (R.isErr(executionResult)) {
return executionResult;
Expand All @@ -88,24 +85,37 @@ export async function executeBlock(
block: BlockDefinition,
executionContext: ExecutionContext,
): Promise<R.Result<IOTypeImplementation | null>> {
const blockExecutor =
executionContext.executionExtension.createBlockExecutor(block);

const startTime = new Date();

await executionContext.executeHooks(inputValue);
logDurationUntilNow(startTime, 'pre-block-hooks', (msg) =>
executionContext.logger.logDebug(msg),
);

if (inputValue == null) {
executionContext.logger.logInfoDiagnostic(
`Skipped execution because parent block emitted no value.`,
{ node: block, property: 'name' },
);
return R.ok(null);
const result = R.ok(null);
const postHookStartTime = new Date();
await executionContext.executeHooks(inputValue, result);
logDurationUntilNow(postHookStartTime, 'post-block-hooks', (msg) =>
executionContext.logger.logDebug(msg),
);
return result;
}

const blockExecutor =
executionContext.executionExtension.createBlockExecutor(block);

const startTime = new Date();
const blockStartTime = new Date();

let result: R.Result<IOTypeImplementation | null>;
try {
result = await blockExecutor.execute(inputValue, executionContext);
} catch (unexpectedError) {
return R.err({
result = R.err({
message: `An unknown error occurred: ${
unexpectedError instanceof Error
? unexpectedError.stack ?? unexpectedError.message
Expand All @@ -114,16 +124,33 @@ export async function executeBlock(
diagnostic: { node: block, property: 'name' },
});
}
logDurationUntilNow(blockStartTime, 'Block', (msg) =>
executionContext.logger.logDebug(msg),
);

const postHookStartTime = new Date();
await executionContext.executeHooks(inputValue, result);
logDurationUntilNow(postHookStartTime, 'post-block-hooks', (msg) =>
executionContext.logger.logDebug(msg),
);

logExecutionDuration(startTime, executionContext.logger);
logDurationUntilNow(startTime, 'Total', (msg) =>
executionContext.logger.logDebug(msg),
);

return result;
}

export function logExecutionDuration(startTime: Date, logger: Logger): void {
export function logExecutionDuration(startTime: Date, logger: Logger) {
logDurationUntilNow(startTime, 'Execution', (msg) => logger.logDebug(msg));
}

function logDurationUntilNow(
startTime: Date,
name: string,
log: (message: string) => void,
) {
const endTime = new Date();
const executionDurationMs = Math.round(
endTime.getTime() - startTime.getTime(),
);
logger.logDebug(`Execution duration: ${executionDurationMs} ms.`);
const durationMs = Math.round(endTime.getTime() - startTime.getTime());
log(`${name} duration: ${durationMs} ms.`);
}
8 changes: 4 additions & 4 deletions libs/execution/src/lib/hooks/hook-context.ts
Original file line number Diff line number Diff line change
Expand Up @@ -111,14 +111,14 @@ export class HookContext {
input: IOTypeImplementation | null,
context: ExecutionContext,
) {
context.logger.logInfo(`Executing general pre-block-hooks`);
context.logger.logDebug(`Executing general pre-block-hooks`);
const general = executePreBlockHooks(
this.hooks.pre[AllBlocks] ?? [],
blocktype,
input,
context,
);
context.logger.logInfo(
context.logger.logDebug(
`Executing pre-block-hooks for blocktype ${blocktype}`,
);
const blockSpecific = executePreBlockHooks(
Expand All @@ -137,15 +137,15 @@ export class HookContext {
context: ExecutionContext,
output: Result<IOTypeImplementation | null>,
) {
context.logger.logInfo(`Executing general post-block-hooks`);
context.logger.logDebug(`Executing general post-block-hooks`);
const general = executePostBlockHooks(
this.hooks.post[AllBlocks] ?? [],
blocktype,
input,
context,
output,
);
context.logger.logInfo(
context.logger.logDebug(
`Executing post-block-hooks for blocktype ${blocktype}`,
);
const blockSpecific = executePostBlockHooks(
Expand Down
Loading