Notebooks: Log telemetry when all markdown cells rendered (#5862)

* Log telemetry when all markdown cells rendered

* Enable referencing previous telemetry timestamps

* Fix broken unit test to do a null check

* Undo loading icon changes in textcelll

* Addressing PR comments

* PR comments II

src/sql/platform/telemetry/telemetryKeys.ts

@@ -60,4 +60,5 @@ export const DeleteAgentAlert = 'DeleteAgentAlert';
 export const DeleteAgentOperator = 'DeleteAgentOperator';
 export const DeleteAgentProxy = 'DeleteAgentProxy';
 
-
+// Notebook Events:
+export const NotebookMarkdownRendered = 'NotebookMarkdownRendered';

src/sql/workbench/parts/notebook/cellViews/textCell.component.html

@@ -5,7 +5,6 @@
  *--------------------------------------------------------------------------------------------*/
 -->
 <div style="overflow: hidden; width: 100%; height: 100%; display: flex; flex-flow: column" (mouseover)="hover=true" (mouseleave)="hover=false">
-	<loading-spinner [loading]="isLoading"></loading-spinner>
 	<div class="notebook-text" style="flex: 0 0 auto;">
 		<code-component *ngIf="isEditMode" [cellModel]="cellModel" (onContentChanged)="handleContentChanged()" [model]="model" [activeCellId]="activeCellId">
 		</code-component>

src/sql/workbench/parts/notebook/cellViews/textCell.component.ts

@@ -75,7 +75,6 @@ export class TextCellComponent extends CellView implements OnInit, AfterContentI
 	private _activeCellId: string;
 	private readonly _onDidClickLink = this._register(new Emitter<URI>());
 	public readonly onDidClickLink = this._onDidClickLink.event;
-	protected isLoading: boolean;
 	private _cellToggleMoreActions: CellToggleMoreActions;
 	private _hover: boolean;
 
@@ -89,7 +88,6 @@ export class TextCellComponent extends CellView implements OnInit, AfterContentI
 	) {
 		super();
 		this.isEditMode = true;
-		this.isLoading = true;
 		this._cellToggleMoreActions = this._instantiationService.createInstance(CellToggleMoreActions);
 	}
 
@@ -110,7 +108,7 @@ export class TextCellComponent extends CellView implements OnInit, AfterContentI
 	}
 
 	private setLoading(isLoading: boolean): void {
-		this.isLoading = isLoading;
+		this.cellModel.loaded = !isLoading;
 		this._changeRef.detectChanges();
 	}
 
@@ -122,7 +120,6 @@ export class TextCellComponent extends CellView implements OnInit, AfterContentI
 		this._register(this.cellModel.onOutputsChanged(e => {
 			this.updatePreview();
 		}));
-		this.setLoading(false);
 	}
 
 	ngAfterContentInit(): void {
@@ -210,6 +207,7 @@ export class TextCellComponent extends CellView implements OnInit, AfterContentI
 				htmlcontent = this.sanitizeContent(htmlcontent);
 				let outputElement = <HTMLElement>this.output.nativeElement;
 				outputElement.innerHTML = htmlcontent;
+				this.setLoading(false);
 			});
 		}
 	}

src/sql/workbench/parts/notebook/models/cell.ts

@@ -40,6 +40,8 @@ export class CellModel implements ICellModel {
 	public id: string;
 	private _connectionManagementService: IConnectionManagementService;
 	private _stdInHandler: nb.MessageHandler<nb.IStdinMessage>;
+	private _onCellLoaded = new Emitter<string>();
+	private _loaded: boolean;
 
 	constructor(cellData: nb.ICellContents,
 		private _options: ICellModelOptions,
@@ -183,6 +185,21 @@ export class CellModel implements ICellModel {
 		this._onExecutionStateChanged.fire(this.executionState);
 	}
 
+	public get onLoaded(): Event<string> {
+		return this._onCellLoaded.event;
+	}
+
+	public get loaded(): boolean {
+		return this._loaded;
+	}
+
+	public set loaded(val: boolean) {
+		this._loaded = val;
+		if (val) {
+			this._onCellLoaded.fire(this._cellType);
+		}
+	}
+
 	private notifyExecutionComplete(): void {
 		if (this._notebookService) {
 			this._notebookService.serializeNotebookStateChange(this.notebookModel.notebookUri, NotebookChangeType.CellExecuted);

src/sql/workbench/parts/notebook/models/modelInterfaces.ts

@@ -466,6 +466,8 @@ export interface ICellModel {
 	setOverrideLanguage(language: string);
 	equals(cellModel: ICellModel): boolean;
 	toJSON(): nb.ICellContents;
+	loaded: boolean;
+	readonly onLoaded: Event<string>;
 }
 
 export interface FutureInternal extends nb.IFuture {
@@ -508,6 +510,7 @@ export interface INotebookModelOptions {
 	notificationService: INotificationService;
 	connectionService: IConnectionManagementService;
 	capabilitiesService: ICapabilitiesService;
+	editorLoadedTimestamp?: number;
 }
 
 export interface ILanguageMagic {

src/sql/workbench/parts/notebook/models/notebookModel.ts

@@ -10,9 +10,10 @@ import { Event, Emitter } from 'vs/base/common/event';
 import { Disposable, IDisposable } from 'vs/base/common/lifecycle';
 
 import { IClientSession, INotebookModel, IDefaultConnection, INotebookModelOptions, ICellModel, NotebookContentChange, notebookConstants } from './modelInterfaces';
-import { NotebookChangeType, CellType } from 'sql/workbench/parts/notebook/models/contracts';
+import { NotebookChangeType, CellType, CellTypes } from 'sql/workbench/parts/notebook/models/contracts';
 import { nbversion } from '../notebookConstants';
 import * as notebookUtils from '../notebookUtils';
+import * as TelemetryKeys from 'sql/platform/telemetry/telemetryKeys';
 import { INotebookManager, SQL_NOTEBOOK_PROVIDER, DEFAULT_NOTEBOOK_PROVIDER } from 'sql/workbench/services/notebook/common/notebookService';
 import { NotebookContexts } from 'sql/workbench/parts/notebook/models/notebookContexts';
 import { IConnectionProfile } from 'sql/platform/connection/common/interfaces';
@@ -23,6 +24,7 @@ import { ConnectionProfile } from 'sql/platform/connection/common/connectionProf
 import { uriPrefixes } from 'sql/platform/connection/common/utils';
 import { keys } from 'vs/base/common/map';
 import { ILogService } from 'vs/platform/log/common/log';
+import { ITelemetryService } from 'vs/platform/telemetry/common/telemetry';
 
 /*
 * Used to control whether a message in a dialog/wizard is displayed as an error,
@@ -72,13 +74,16 @@ export class NotebookModel extends Disposable implements INotebookModel {
 	private _oldKernel: nb.IKernel;
 	private _clientSessionListeners: IDisposable[] = [];
 	private _connectionUrisToDispose: string[] = [];
+	private _textCellsLoading: number = 0;
+
 	public requestConnectionHandler: () => Promise<boolean>;
 
 	constructor(
 		private _notebookOptions: INotebookModelOptions,
 		public connectionProfile: IConnectionProfile | undefined,
 		@ILogService private readonly logService: ILogService,
-		@INotificationService private readonly notificationService: INotificationService
+		@INotificationService private readonly notificationService: INotificationService,
+		@ITelemetryService private readonly telemetryService: ITelemetryService
 	) {
 		super();
 		if (!_notebookOptions || !_notebookOptions.notebookUri || !_notebookOptions.notebookManagers) {
@@ -292,7 +297,11 @@ export class NotebookModel extends Disposable implements INotebookModel {
 				this._defaultLanguageInfo = this.getDefaultLanguageInfo(contents);
 				this._savedKernelInfo = this.getSavedKernelInfo(contents);
 				if (contents.cells && contents.cells.length > 0) {
-					this._cells = contents.cells.map(c => factory.createCell(c, { notebook: this, isTrusted: isTrusted }));
+					this._cells = contents.cells.map(c => {
+						let cellModel = factory.createCell(c, { notebook: this, isTrusted: isTrusted });
+						this.trackMarkdownTelemetry(<nb.ICellContents>c, cellModel);
+						return cellModel;
+					});
 				}
 			}
 			this.setDefaultKernelAndProviderId();
@@ -920,6 +929,26 @@ export class NotebookModel extends Disposable implements INotebookModel {
 		this._connectionUrisToDispose = [];
 	}
 
+	/**
+	 * Track time it takes to render all markdown cells
+	 */
+	private trackMarkdownTelemetry(cellContent: nb.ICellContents, cellModel: ICellModel): void {
+		if (cellContent && cellContent.cell_type === CellTypes.Markdown) {
+			this._textCellsLoading++;
+		}
+		this._register(cellModel.onLoaded((cell_type) => {
+			if (cell_type === CellTypes.Markdown) {
+				this._textCellsLoading--;
+				if (this._textCellsLoading <= 0) {
+					if (this._notebookOptions.editorLoadedTimestamp) {
+						let markdownRenderingTime = Date.now() - this._notebookOptions.editorLoadedTimestamp;
+						this.telemetryService.publicLog(TelemetryKeys.NotebookMarkdownRendered, { markdownRenderingElapsedMs: markdownRenderingTime });
+					}
+				}
+			}
+		}));
+	}
+
 	/**
 	 * Serialize the model to JSON.
 	 */

src/sql/workbench/parts/notebook/notebook.component.ts

@@ -48,6 +48,7 @@ import { toErrorMessage } from 'vs/base/common/errorMessage';
 import { ILogService } from 'vs/platform/log/common/log';
 import { ITextFileService } from 'vs/workbench/services/textfile/common/textfiles';
 import { LabeledMenuItemActionItem, fillInActions } from 'vs/platform/actions/browser/menuEntryActionViewItem';
+import { ITelemetryService } from 'vs/platform/telemetry/common/telemetry';
 
 
 export const NOTEBOOK_SELECTOR: string = 'notebook-component';
@@ -94,7 +95,8 @@ export class NotebookComponent extends AngularDisposable implements OnInit, OnDe
 		@Inject(IViewletService) private viewletService: IViewletService,
 		@Inject(ICapabilitiesService) private capabilitiesService: ICapabilitiesService,
 		@Inject(ITextFileService) private textFileService: ITextFileService,
-		@Inject(ILogService) private readonly logService: ILogService
+		@Inject(ILogService) private readonly logService: ILogService,
+		@Inject(ITelemetryService) private telemetryService: ITelemetryService
 	) {
 		super();
 		this.updateProfile();
@@ -278,8 +280,9 @@ export class NotebookComponent extends AngularDisposable implements OnInit, OnDe
 			providerId: 'sql', // this is tricky; really should also depend on the connection profile
 			defaultKernel: this._notebookParams.input.defaultKernel,
 			layoutChanged: this._notebookParams.input.layoutChanged,
-			capabilitiesService: this.capabilitiesService
+			capabilitiesService: this.capabilitiesService,
-		}, this.profile, this.logService, this.notificationService);
+			editorLoadedTimestamp: this._notebookParams.input.editorOpenedTimestamp
+		}, this.profile, this.logService, this.notificationService, this.telemetryService);
 		model.onError((errInfo: INotification) => this.handleModelError(errInfo));
 		let trusted = await this.notebookService.isNotebookTrustCached(this._notebookParams.notebookUri, this.isDirty());
 		await model.requestModelLoad(trusted);

src/sql/workbench/parts/notebook/notebookInput.ts

@@ -155,6 +155,7 @@ export class NotebookInput extends EditorInput {
 	private _contentManager: IContentManager;
 	private _providersLoaded: Promise<void>;
 	private _dirtyListener: IDisposable;
+	private _notebookEditorOpenedTimestamp: number;
 
 	constructor(private _title: string,
 		private resource: URI,
@@ -168,6 +169,7 @@ export class NotebookInput extends EditorInput {
 		this.resource = resource;
 		this._standardKernels = [];
 		this._providersLoaded = this.assignProviders();
+		this._notebookEditorOpenedTimestamp = Date.now();
 		if (this._textInput) {
 			this.hookDirtyListener(this._textInput.onDidChangeDirty, () => this._onDidChangeDirty.fire());
 		}
@@ -251,6 +253,10 @@ export class NotebookInput extends EditorInput {
 		return this._layoutChanged.event;
 	}
 
+	public get editorOpenedTimestamp(): number {
+		return this._notebookEditorOpenedTimestamp;
+	}
+
 	doChangeLayout(): any {
 		this._layoutChanged.fire();
 	}

src/sqltest/parts/notebook/model/notebookModel.test.ts

@@ -138,7 +138,7 @@ suite('notebook model', function (): void {
 		mockContentManager.setup(c => c.getNotebookContents(TypeMoq.It.isAny())).returns(() => Promise.resolve(emptyNotebook));
 		notebookManagers[0].contentManager = mockContentManager.object;
 		// When I initialize the model
-		let model = new NotebookModel(defaultModelOptions, undefined, logService, undefined);
+		let model = new NotebookModel(defaultModelOptions, undefined, logService, undefined, undefined);
 		await model.requestModelLoad();
 
 		// Then I expect to have 0 code cell as the contents
@@ -153,7 +153,7 @@ suite('notebook model', function (): void {
 		mockContentManager.setup(c => c.getNotebookContents(TypeMoq.It.isAny())).returns(() => Promise.resolve(expectedNotebookContent));
 		notebookManagers[0].contentManager = mockContentManager.object;
 		// When I initialize the model
-		let model = new NotebookModel(defaultModelOptions, undefined, logService, undefined);
+		let model = new NotebookModel(defaultModelOptions, undefined, logService, undefined, undefined);
 		await model.requestModelLoad(true);
 
 		// Then Trust should be true
@@ -240,7 +240,7 @@ suite('notebook model', function (): void {
 		let options: INotebookModelOptions = Object.assign({}, defaultModelOptions, <Partial<INotebookModelOptions>>{
 			factory: mockModelFactory.object
 		});
-		let model = new NotebookModel(options, undefined, logService, undefined);
+		let model = new NotebookModel(options, undefined, logService, undefined, undefined);
 		model.onClientSessionReady((session) => actualSession = session);
 		await model.requestModelLoad();
 		await model.startSession(notebookManagers[0]);
@@ -258,14 +258,14 @@ suite('notebook model', function (): void {
 	});
 
 	test('Should sanitize kernel display name when IP is included', async function (): Promise<void> {
-		let model = new NotebookModel(defaultModelOptions, undefined, logService, undefined);
+		let model = new NotebookModel(defaultModelOptions, undefined, logService, undefined, undefined);
 		let displayName = 'PySpark (1.1.1.1)';
 		let sanitizedDisplayName = model.sanitizeDisplayName(displayName);
 		should(sanitizedDisplayName).equal('PySpark');
 	});
 
 	test('Should sanitize kernel display name properly when IP is not included', async function (): Promise<void> {
-		let model = new NotebookModel(defaultModelOptions, undefined, logService, undefined);
+		let model = new NotebookModel(defaultModelOptions, undefined, logService, undefined, undefined);
 		let displayName = 'PySpark';
 		let sanitizedDisplayName = model.sanitizeDisplayName(displayName);
 		should(sanitizedDisplayName).equal('PySpark');
@@ -276,7 +276,7 @@ suite('notebook model', function (): void {
 		let mockContentManager = TypeMoq.Mock.ofType(LocalContentManager);
 		mockContentManager.setup(c => c.getNotebookContents(TypeMoq.It.isAny())).returns(() => Promise.resolve(expectedNotebookContent));
 		notebookManagers[0].contentManager = mockContentManager.object;
-		let model = new NotebookModel(defaultModelOptions, undefined, logService, undefined);
+		let model = new NotebookModel(defaultModelOptions, undefined, logService, undefined, undefined);
 		await model.requestModelLoad(false);
 
 		let actualChanged: NotebookContentChange;