From a5e68b6fdb23dd556f549aa16cfd69d187762533 Mon Sep 17 00:00:00 2001 From: Saul Shanabrook Date: Thu, 4 Oct 2018 15:39:00 -0400 Subject: [PATCH 1/5] Record timings in metadata --- packages/cells/src/widget.ts | 30 +++++++++++++++++++++++++++-- tests/test-cells/src/widget.spec.ts | 8 ++++++++ 2 files changed, 36 insertions(+), 2 deletions(-) diff --git a/packages/cells/src/widget.ts b/packages/cells/src/widget.ts index b9191cd04029..b1b19220d8d0 100644 --- a/packages/cells/src/widget.ts +++ b/packages/cells/src/widget.ts @@ -1025,7 +1025,7 @@ export namespace CodeCell { cell.outputHidden = false; cell.setPrompt('*'); model.trusted = true; - +// let future: Kernel.IFuture< KernelMessage.IExecuteRequestMsg, KernelMessage.IExecuteReplyMsg @@ -1037,10 +1037,36 @@ export namespace CodeCell { session, metadata ); + cell.outputArea.future.onIOPub = (msg: KernelMessage.IIOPubMessage) => { + let label: string; + switch (msg.header.msg_type) { + case 'status': + label = `status.${(msg as KernelMessage.IStatusMsg).content.execution_state}`; + break; + case 'execute_input': + label = 'execute_input'; + break; + default: + return; + } + const value = msg.header.date; + if (!value) { + return; + } + model.metadata.set(`timing.iopub.${label}`, value); + }; // Save this execution's future so we can compare in the catch below. future = cell.outputArea.future; const msg = await msgPromise; model.executionCount = msg.content.execution_count; + const started = msg.metadata.started as string; + if (started) { + model.metadata.set('timing.shell.execute_reply.started', started); + } + const date = msg.header.date as string; + if (date) { + model.metadata.set('timing.shell.execute_reply', date); + } return msg; } catch (e) { // If this is still the current execution, clear the prompt. @@ -1049,7 +1075,7 @@ export namespace CodeCell { } throw e; } - } + } } /****************************************************************************** diff --git a/tests/test-cells/src/widget.spec.ts b/tests/test-cells/src/widget.spec.ts index ba5bbfedf6e1..8189a87db5f4 100644 --- a/tests/test-cells/src/widget.spec.ts +++ b/tests/test-cells/src/widget.spec.ts @@ -754,6 +754,14 @@ describe('cells/widget', () => { await CodeCell.execute(widget, session); const executionCount = widget.model.executionCount; expect(executionCount).not.toEqual(originalCount); + expect(widget.model.metadata.get('timing.iopub.execute_input')).to + .exist; + expect(widget.model.metadata.get('timing.shell.execute_reply.started')) + .to.exist; + expect(widget.model.metadata.get('timing.shell.execute_reply')).to + .exist; + expect(widget.model.metadata.get('timing.iopub.status.busy')).to.exist; + expect(widget.model.metadata.get('timing.iopub.status.idle')).to.exist; }); it('should set the cell prompt properly while executing', async () => { From 980f61590d675c62ce5bb446c270be59b09a5708 Mon Sep 17 00:00:00 2001 From: Saul Shanabrook Date: Thu, 4 Oct 2018 17:06:22 -0400 Subject: [PATCH 2/5] Add ability to toggle saving execution timing --- packages/cells/src/widget.ts | 16 ++++++------ packages/notebook-extension/src/index.ts | 14 ++++++++++ packages/notebook/src/actions.tsx | 16 +++++++++++- tests/test-cells/src/widget.spec.ts | 33 +++++++++++++++++------- 4 files changed, 61 insertions(+), 18 deletions(-) diff --git a/packages/cells/src/widget.ts b/packages/cells/src/widget.ts index b1b19220d8d0..c58136ca5ed7 100644 --- a/packages/cells/src/widget.ts +++ b/packages/cells/src/widget.ts @@ -1018,14 +1018,12 @@ export namespace CodeCell { model.outputs.clear(); return; } - - let cellId = { cellId: model.id }; - metadata = { ...metadata, ...cellId }; + metadata = { ...metadata, cellId: model.id }; + const { recordTiming } = metadata; model.executionCount = null; cell.outputHidden = false; cell.setPrompt('*'); model.trusted = true; -// let future: Kernel.IFuture< KernelMessage.IExecuteRequestMsg, KernelMessage.IExecuteReplyMsg @@ -1037,6 +1035,8 @@ export namespace CodeCell { session, metadata ); + // cell.outputArea.future assigned synchronously in `execute` + if (recordTiming) { cell.outputArea.future.onIOPub = (msg: KernelMessage.IIOPubMessage) => { let label: string; switch (msg.header.msg_type) { @@ -1054,17 +1054,17 @@ export namespace CodeCell { return; } model.metadata.set(`timing.iopub.${label}`, value); - }; + }}; // Save this execution's future so we can compare in the catch below. future = cell.outputArea.future; const msg = await msgPromise; model.executionCount = msg.content.execution_count; const started = msg.metadata.started as string; - if (started) { + if (recordTiming && started) { model.metadata.set('timing.shell.execute_reply.started', started); } const date = msg.header.date as string; - if (date) { + if (recordTiming && date) { model.metadata.set('timing.shell.execute_reply', date); } return msg; @@ -1075,7 +1075,7 @@ export namespace CodeCell { } throw e; } - } + } } /****************************************************************************** diff --git a/packages/notebook-extension/src/index.ts b/packages/notebook-extension/src/index.ts index e88150e6230a..8b3755a6fd6f 100644 --- a/packages/notebook-extension/src/index.ts +++ b/packages/notebook-extension/src/index.ts @@ -173,6 +173,8 @@ namespace CommandIDs { export const toggleAllLines = 'notebook:toggle-all-cell-line-numbers'; + export const toggleRecordTiming = 'notebook:toggle-record-timing'; + export const undoCellAction = 'notebook:undo-cell-action'; export const redoCellAction = 'notebook:redo-cell-action'; @@ -1520,6 +1522,17 @@ function addCommands( }, isEnabled }); + commands.addCommand(CommandIDs.toggleRecordTiming, { + label: 'Toggle Recording Cell Timing', + execute: args => { + const current = getCurrent(args); + + if (current) { + return NotebookActions.toggleRecordTiming(current.content); + } + }, + isEnabled + }) commands.addCommand(CommandIDs.commandMode, { label: 'Enter Command Mode', execute: args => { @@ -1858,6 +1871,7 @@ function populatePalette( CommandIDs.deselectAll, CommandIDs.clearAllOutputs, CommandIDs.toggleAllLines, + CommandIDs.toggleRecordTiming, CommandIDs.editMode, CommandIDs.commandMode, CommandIDs.changeKernel, diff --git a/packages/notebook/src/actions.tsx b/packages/notebook/src/actions.tsx index 3c1733ab633e..1a532c880e9c 100644 --- a/packages/notebook/src/actions.tsx +++ b/packages/notebook/src/actions.tsx @@ -980,6 +980,19 @@ export namespace NotebookActions { Private.handleState(notebook, state); } + /** + * Toggle whether to record cell timing execution. + * + * @param notebook - The target notebook widget. + */ + export function toggleRecordTiming(notebook: Notebook): void { + if (!notebook.model) { + return; + } + const currentValue = notebook.model.metadata.get('record_timing') || false; + notebook.model.metadata.set('record_timing', !currentValue); + } + /** * Clear the code outputs of the selected cells. * @@ -1472,7 +1485,8 @@ namespace Private { case 'code': if (session) { return CodeCell.execute(cell as CodeCell, session, { - deletedCells: notebook.model.deletedCells + deletedCells: notebook.model.deletedCells, + recordTiming: notebook.model.metadata.get('record_timing') || false }) .then(reply => { notebook.model.deletedCells.splice( diff --git a/tests/test-cells/src/widget.spec.ts b/tests/test-cells/src/widget.spec.ts index 8189a87db5f4..c351c34ca292 100644 --- a/tests/test-cells/src/widget.spec.ts +++ b/tests/test-cells/src/widget.spec.ts @@ -753,15 +753,30 @@ describe('cells/widget', () => { originalCount = widget.model.executionCount; await CodeCell.execute(widget, session); const executionCount = widget.model.executionCount; - expect(executionCount).not.toEqual(originalCount); - expect(widget.model.metadata.get('timing.iopub.execute_input')).to - .exist; - expect(widget.model.metadata.get('timing.shell.execute_reply.started')) - .to.exist; - expect(widget.model.metadata.get('timing.shell.execute_reply')).to - .exist; - expect(widget.model.metadata.get('timing.iopub.status.busy')).to.exist; - expect(widget.model.metadata.get('timing.iopub.status.idle')).to.exist; + expect(executionCount).to.not.equal(originalCount); + }); + + const TIMING_KEYS = [ + 'timing.iopub.execute_input', + 'timing.shell.execute_reply.started', + 'timing.shell.execute_reply', + 'timing.iopub.status.busy', + 'timing.iopub.status.idle' + ]; + + it('should not save timing info by default', async () => { + const widget = new CodeCell({ model, rendermime, contentFactory }); + await CodeCell.execute(widget, session); + for (const key of TIMING_KEYS) { + expect(widget.model.metadata.get(key)).to.not.exist; + } + }); + it('should save timing info if requested', async () => { + const widget = new CodeCell({ model, rendermime, contentFactory }); + await CodeCell.execute(widget, session, { recordTiming: true }); + for (const key of TIMING_KEYS) { + expect(widget.model.metadata.get(key)).to.exist; + } }); it('should set the cell prompt properly while executing', async () => { From 2e7208559fb273d911bcb06fa5c8e7754ffc5b5c Mon Sep 17 00:00:00 2001 From: Saul Shanabrook Date: Fri, 5 Oct 2018 10:17:49 -0400 Subject: [PATCH 3/5] prettier --- packages/notebook-extension/src/index.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/notebook-extension/src/index.ts b/packages/notebook-extension/src/index.ts index 8b3755a6fd6f..06757cb5a934 100644 --- a/packages/notebook-extension/src/index.ts +++ b/packages/notebook-extension/src/index.ts @@ -1532,7 +1532,7 @@ function addCommands( } }, isEnabled - }) + }); commands.addCommand(CommandIDs.commandMode, { label: 'Enter Command Mode', execute: args => { From 08c9b7ddeb462ff9142671dbcb2f7806d4b9392b Mon Sep 17 00:00:00 2001 From: madhu94 Date: Sun, 21 Jul 2019 20:26:12 +0530 Subject: [PATCH 4/5] Move timing to a sub dict, fix relevant tests Use registerMessageHook to avoid overriding the default iopub callback for outputarea --- packages/cells/src/widget.ts | 59 +++++++++++++++++------------ tests/test-cells/src/widget.spec.ts | 20 +++++----- 2 files changed, 45 insertions(+), 34 deletions(-) diff --git a/packages/cells/src/widget.ts b/packages/cells/src/widget.ts index c58136ca5ed7..325d02b13664 100644 --- a/packages/cells/src/widget.ts +++ b/packages/cells/src/widget.ts @@ -1035,37 +1035,48 @@ export namespace CodeCell { session, metadata ); - // cell.outputArea.future assigned synchronously in `execute` - if (recordTiming) { - cell.outputArea.future.onIOPub = (msg: KernelMessage.IIOPubMessage) => { - let label: string; - switch (msg.header.msg_type) { - case 'status': - label = `status.${(msg as KernelMessage.IStatusMsg).content.execution_state}`; - break; - case 'execute_input': - label = 'execute_input'; - break; - default: + // cell.outputArea.future assigned synchronously in `execute` + if (recordTiming) { + const recordTimingHook = (msg: KernelMessage.IIOPubMessage) => { + let label: string; + switch (msg.header.msg_type) { + case 'status': + label = `status.${ + (msg as KernelMessage.IStatusMsg).content.execution_state + }`; + break; + case 'execute_input': + label = 'execute_input'; + break; + default: + return; + } + const value = msg.header.date; + if (!value) { return; - } - const value = msg.header.date; - if (!value) { - return; - } - model.metadata.set(`timing.iopub.${label}`, value); - }}; + } + const timingInfo: any = model.metadata.get('timing') || {}; + timingInfo[`iopub.${label}`] = value; + model.metadata.set('timing', timingInfo); + return true; + }; + cell.outputArea.future.registerMessageHook(recordTimingHook); + } // Save this execution's future so we can compare in the catch below. future = cell.outputArea.future; const msg = await msgPromise; model.executionCount = msg.content.execution_count; const started = msg.metadata.started as string; if (recordTiming && started) { - model.metadata.set('timing.shell.execute_reply.started', started); - } - const date = msg.header.date as string; - if (recordTiming && date) { - model.metadata.set('timing.shell.execute_reply', date); + const timingInfo = (model.metadata.get('timing') as any) || {}; + if (started) { + timingInfo['shell.execute_reply.started'] = started; + } + const date = msg.header.date as string; + if (date) { + timingInfo['shell.execute_reply'] = date; + } + model.metadata.set('timing', timingInfo); } return msg; } catch (e) { diff --git a/tests/test-cells/src/widget.spec.ts b/tests/test-cells/src/widget.spec.ts index c351c34ca292..eee3dd956387 100644 --- a/tests/test-cells/src/widget.spec.ts +++ b/tests/test-cells/src/widget.spec.ts @@ -753,29 +753,29 @@ describe('cells/widget', () => { originalCount = widget.model.executionCount; await CodeCell.execute(widget, session); const executionCount = widget.model.executionCount; - expect(executionCount).to.not.equal(originalCount); + expect(executionCount).not.toEqual(originalCount); }); const TIMING_KEYS = [ - 'timing.iopub.execute_input', - 'timing.shell.execute_reply.started', - 'timing.shell.execute_reply', - 'timing.iopub.status.busy', - 'timing.iopub.status.idle' + 'iopub.execute_input', + 'shell.execute_reply.started', + 'shell.execute_reply', + 'iopub.status.busy', + 'iopub.status.idle' ]; it('should not save timing info by default', async () => { const widget = new CodeCell({ model, rendermime, contentFactory }); await CodeCell.execute(widget, session); - for (const key of TIMING_KEYS) { - expect(widget.model.metadata.get(key)).to.not.exist; - } + expect(widget.model.metadata.get('timing')).toBeUndefined(); }); it('should save timing info if requested', async () => { const widget = new CodeCell({ model, rendermime, contentFactory }); await CodeCell.execute(widget, session, { recordTiming: true }); + expect(widget.model.metadata.get('timing')).toBeDefined(); + const timingInfo = widget.model.metadata.get('timing') as any; for (const key of TIMING_KEYS) { - expect(widget.model.metadata.get(key)).to.exist; + expect(timingInfo[key]).toBeDefined(); } }); From e5c593d2163273de792f66909c2400d9ed048226 Mon Sep 17 00:00:00 2001 From: madhu94 Date: Wed, 21 Aug 2019 01:07:00 +0530 Subject: [PATCH 5/5] Rename timing to execution --- packages/cells/src/widget.ts | 8 ++++---- tests/test-cells/src/widget.spec.ts | 6 +++--- 2 files changed, 7 insertions(+), 7 deletions(-) diff --git a/packages/cells/src/widget.ts b/packages/cells/src/widget.ts index 325d02b13664..e54cf17fe6b8 100644 --- a/packages/cells/src/widget.ts +++ b/packages/cells/src/widget.ts @@ -1055,9 +1055,9 @@ export namespace CodeCell { if (!value) { return; } - const timingInfo: any = model.metadata.get('timing') || {}; + const timingInfo: any = model.metadata.get('execution') || {}; timingInfo[`iopub.${label}`] = value; - model.metadata.set('timing', timingInfo); + model.metadata.set('execution', timingInfo); return true; }; cell.outputArea.future.registerMessageHook(recordTimingHook); @@ -1068,7 +1068,7 @@ export namespace CodeCell { model.executionCount = msg.content.execution_count; const started = msg.metadata.started as string; if (recordTiming && started) { - const timingInfo = (model.metadata.get('timing') as any) || {}; + const timingInfo = (model.metadata.get('execution') as any) || {}; if (started) { timingInfo['shell.execute_reply.started'] = started; } @@ -1076,7 +1076,7 @@ export namespace CodeCell { if (date) { timingInfo['shell.execute_reply'] = date; } - model.metadata.set('timing', timingInfo); + model.metadata.set('execution', timingInfo); } return msg; } catch (e) { diff --git a/tests/test-cells/src/widget.spec.ts b/tests/test-cells/src/widget.spec.ts index eee3dd956387..b39e777e862a 100644 --- a/tests/test-cells/src/widget.spec.ts +++ b/tests/test-cells/src/widget.spec.ts @@ -767,13 +767,13 @@ describe('cells/widget', () => { it('should not save timing info by default', async () => { const widget = new CodeCell({ model, rendermime, contentFactory }); await CodeCell.execute(widget, session); - expect(widget.model.metadata.get('timing')).toBeUndefined(); + expect(widget.model.metadata.get('execution')).toBeUndefined(); }); it('should save timing info if requested', async () => { const widget = new CodeCell({ model, rendermime, contentFactory }); await CodeCell.execute(widget, session, { recordTiming: true }); - expect(widget.model.metadata.get('timing')).toBeDefined(); - const timingInfo = widget.model.metadata.get('timing') as any; + expect(widget.model.metadata.get('execution')).toBeDefined(); + const timingInfo = widget.model.metadata.get('execution') as any; for (const key of TIMING_KEYS) { expect(timingInfo[key]).toBeDefined(); }