From 9f1a49249d0f4bf218ea6ec0d4cb48ff92a15e31 Mon Sep 17 00:00:00 2001 From: Don Jayamanne Date: Mon, 23 Jan 2023 10:40:00 +1100 Subject: [PATCH 1/2] Add logging for exe start and stop times --- src/kernels/execution/cellExecutionCreator.ts | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/src/kernels/execution/cellExecutionCreator.ts b/src/kernels/execution/cellExecutionCreator.ts index 16c50ec571e..8a531d6201c 100644 --- a/src/kernels/execution/cellExecutionCreator.ts +++ b/src/kernels/execution/cellExecutionCreator.ts @@ -11,6 +11,7 @@ import { NotebookCellOutputItem, TextDocument } from 'vscode'; +import { traceVerbose } from '../../platform/logging'; import { sendTelemetryEvent, Telemetry } from '../../telemetry'; import { IKernelController } from '../types'; @@ -21,6 +22,7 @@ import { IKernelController } from '../types'; */ export class NotebookCellExecutionWrapper implements NotebookCellExecution { public started: boolean = false; + private _startTime?: number; constructor( private readonly _impl: NotebookCellExecution, public controllerId: string, @@ -43,12 +45,19 @@ export class NotebookCellExecutionWrapper implements NotebookCellExecution { if (!this.started) { this.started = true; this._impl.start(startTime); + this._startTime = startTime; + traceVerbose(`Start cell ${this.cell.index} execution @ ${startTime}`); } } end(success: boolean | undefined, endTime?: number): void { if (this._endCallback) { try { this._impl.end(success, endTime); + traceVerbose( + `End cell ${this.cell.index} execution @ ${endTime}, started @ ${this._startTime}, elapsed time = ${ + (endTime || 0) - (this._startTime || 0) + }` + ); } finally { this._endCallback(); this._endCallback = undefined; From b5978db7a6438bc5b1a6f47f5e1a68ba2e633b6e Mon Sep 17 00:00:00 2001 From: Don Jayamanne Date: Mon, 23 Jan 2023 10:43:52 +1100 Subject: [PATCH 2/2] Misc --- src/kernels/execution/cellExecutionCreator.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/kernels/execution/cellExecutionCreator.ts b/src/kernels/execution/cellExecutionCreator.ts index 8a531d6201c..adc1e3927ce 100644 --- a/src/kernels/execution/cellExecutionCreator.ts +++ b/src/kernels/execution/cellExecutionCreator.ts @@ -55,8 +55,8 @@ export class NotebookCellExecutionWrapper implements NotebookCellExecution { this._impl.end(success, endTime); traceVerbose( `End cell ${this.cell.index} execution @ ${endTime}, started @ ${this._startTime}, elapsed time = ${ - (endTime || 0) - (this._startTime || 0) - }` + ((endTime || 0) - (this._startTime || 0)) / 1000 + }s` ); } finally { this._endCallback();