Skip to content

Commit b5b15c1

Browse files
author
Benjamin Pasero
committed
storage - tweak performance numbers
1 parent 4626bc0 commit b5b15c1

7 files changed

Lines changed: 90 additions & 33 deletions

File tree

‎src/vs/base/node/storage.ts‎

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@ import { RunOnceScheduler } from 'vs/base/common/async';
1010
import { isUndefinedOrNull } from 'vs/base/common/types';
1111
import { mapToString, setToString } from 'vs/base/common/map';
1212
import { basename } from 'path';
13+
import { mark } from 'vs/base/common/performance';
1314

1415
export interface IStorageOptions {
1516
path: string;
@@ -228,6 +229,9 @@ export interface IUpdateRequest {
228229
}
229230

230231
export class SQLiteStorageImpl {
232+
233+
private static measuredRequireDuration: boolean; // TODO@Ben remove me after a while
234+
231235
private db: Promise<Database>;
232236
private name: string;
233237
private logger: SQLiteStorageLogger;
@@ -337,7 +341,18 @@ export class SQLiteStorageImpl {
337341

338342
private doOpen(path: string): Promise<Database> {
339343
return new Promise((resolve, reject) => {
344+
let measureRequireDuration = false;
345+
if (!SQLiteStorageImpl.measuredRequireDuration) {
346+
SQLiteStorageImpl.measuredRequireDuration = true;
347+
measureRequireDuration = true;
348+
349+
mark('willRequireSQLite');
350+
}
340351
import('vscode-sqlite3').then(sqlite3 => {
352+
if (measureRequireDuration) {
353+
mark('didRequireSQLite');
354+
}
355+
341356
const db = new (this.logger.verbose ? sqlite3.verbose().Database : sqlite3.Database)(path, error => {
342357
if (error) {
343358
return reject(error);

‎src/vs/code/electron-browser/workbench/workbench.js‎

Lines changed: 2 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -53,15 +53,11 @@ bootstrapWindow.load([
5353
function showPartsSplash(configuration) {
5454
perf.mark('willShowPartsSplash');
5555

56-
// TODO@Ben remove me after a while
57-
perf.mark('willAccessLocalStorage');
58-
let storage = window.localStorage;
59-
perf.mark('didAccessLocalStorage');
60-
6156
let data;
6257
try {
58+
// TODO@Ben remove me after a while
6359
perf.mark('willReadLocalStorage');
64-
let raw = storage.getItem('storage://global/parts-splash-data');
60+
let raw = window.localStorage.getItem('storage://global/parts-splash-data');
6561
perf.mark('didReadLocalStorage');
6662
data = JSON.parse(raw);
6763
} catch (e) {

‎src/vs/platform/storage/node/storageService.ts‎

Lines changed: 13 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -29,6 +29,10 @@ export class StorageService extends Disposable implements IStorageService {
2929
private _onWillSaveState: Emitter<void> = this._register(new Emitter<void>());
3030
get onWillSaveState(): Event<void> { return this._onWillSaveState.event; }
3131

32+
33+
private _hasErrors = false;
34+
get hasErrors(): boolean { return this._hasErrors; }
35+
3236
private bufferedStorageErrors: (string | Error)[] = [];
3337
private _onStorageError: Emitter<string | Error> = this._register(new Emitter<string | Error>());
3438
get onStorageError(): Event<string | Error> {
@@ -69,6 +73,8 @@ export class StorageService extends Disposable implements IStorageService {
6973
errorLogger: error => {
7074
logService.error(error);
7175

76+
this._hasErrors = true;
77+
7278
if (Array.isArray(this.bufferedStorageErrors)) {
7379
this.bufferedStorageErrors.push(error);
7480
} else {
@@ -101,13 +107,15 @@ export class StorageService extends Disposable implements IStorageService {
101107
}
102108

103109
init(): Promise<void> {
104-
mark('willInitGlobalStorage');
105110
mark('willInitWorkspaceStorage');
111+
return this.workspaceStorage.init().then(() => {
112+
mark('didInitWorkspaceStorage');
106113

107-
return Promise.all([
108-
this.globalStorage.init().then(() => mark('didInitGlobalStorage')),
109-
this.workspaceStorage.init().then(() => mark('didInitWorkspaceStorage'))
110-
]).then(() => void 0);
114+
mark('willInitGlobalStorage');
115+
return this.globalStorage.init().then(() => {
116+
mark('didInitGlobalStorage');
117+
});
118+
});
111119
}
112120

113121
get(key: string, scope: StorageScope, fallbackValue: string): string;

‎src/vs/workbench/electron-browser/main.ts‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -292,14 +292,18 @@ function createStorageService(workspaceStorageFolder: string, payload: IWorkspac
292292
// Otherwise do a migration of previous workspace data if the DB does not exist yet
293293
// TODO@Ben remove me after one milestone
294294
const workspaceStorageDBPath = join(workspaceStorageFolder, 'storage.db');
295+
perf.mark('willCheckWorkspaceStorageExists');
295296
return exists(workspaceStorageDBPath).then(exists => {
297+
perf.mark('didCheckWorkspaceStorageExists');
298+
296299
const storageService = new StorageService(workspaceStorageDBPath, logService, environmentService);
297300

298301
return storageService.init().then(() => {
299302
if (exists) {
300303
return storageService; // return early if DB was already there
301304
}
302305

306+
perf.mark('willMigrateWorkspaceStorageKeys');
303307
return readdir(environmentService.extensionsPath).then(extensions => {
304308

305309
// Otherwise, we migrate data from window.localStorage over
@@ -417,6 +421,8 @@ function createStorageService(workspaceStorageFolder: string, payload: IWorkspac
417421
logService.error(error);
418422
}
419423

424+
perf.mark('didMigrateWorkspaceStorageKeys');
425+
420426
return storageService;
421427
});
422428
});

‎src/vs/workbench/electron-browser/shell.ts‎

Lines changed: 40 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -286,12 +286,14 @@ export class WorkbenchShell extends Disposable {
286286

287287
private logStorageTelemetry(): void {
288288
const globalStorageInitDuration = perf.getDuration('willInitGlobalStorage', 'didInitGlobalStorage');
289+
const workspaceStorageRequireDuration = perf.getDuration('willRequireSQLite', 'didRequireSQLite');
289290
const workspaceStorageInitDuration = perf.getDuration('willInitWorkspaceStorage', 'didInitWorkspaceStorage');
291+
const workspaceStorageFileExistsDuration = perf.getDuration('willCheckWorkspaceStorageExists', 'didCheckWorkspaceStorageExists');
292+
const workspaceStorageMigrationDuration = perf.getDuration('willMigrateWorkspaceStorageKeys', 'didMigrateWorkspaceStorageKeys');
290293
const workbenchLoadDuration = perf.getDuration('willLoadWorkbenchMain', 'didLoadWorkbenchMain');
291-
const localStorageAccessDuration = perf.getDuration('willAccessLocalStorage', 'didAccessLocalStorage');
292-
const localStorageReadDuration = perf.getDuration('willReadLocalStorage', 'didReadLocalStorage');
294+
const localStorageDuration = perf.getDuration('willReadLocalStorage', 'didReadLocalStorage');
293295

294-
let workspaceIntegrity: string;
296+
let workspaceIntegrity = 'unresolved';
295297

296298
// Handle errors (avoid duplicates to reduce spam)
297299
const loggedStorageErrors = new Set<string>();
@@ -302,29 +304,33 @@ export class WorkbenchShell extends Disposable {
302304
loggedStorageErrors.add(errorStr);
303305

304306
/* __GDPR__
305-
"sqliteStorageError2" : {
307+
"sqliteStorageError3" : {
306308
"globalReadTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
309+
"workspaceExistsTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
310+
"workspaceRequireTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
307311
"workspaceReadTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
308-
"localStorageAccessTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
309-
"localStorageReadTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
312+
"workspaceMigrationTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
313+
"localStorageTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
310314
"workbenchRequireTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
311315
"globalKeys" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
312316
"workspaceKeys" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
313317
"startupKind": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
314-
"workspaceIntegrity" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
318+
"integrityWorkspace" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
315319
"storageError": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true }
316320
}
317321
*/
318-
this.telemetryService.publicLog('sqliteStorageError2', {
322+
this.telemetryService.publicLog('sqliteStorageError3', {
319323
'globalReadTime': globalStorageInitDuration,
324+
'workspaceExistsTime': workspaceStorageFileExistsDuration,
325+
'workspaceMigrationTime': workspaceStorageMigrationDuration,
326+
'workspaceRequireTime': workspaceStorageRequireDuration,
320327
'workspaceReadTime': workspaceStorageInitDuration,
321-
'localStorageAccessTime': localStorageAccessDuration,
322-
'localStorageReadTime': localStorageReadDuration,
328+
'localStorageTime': localStorageDuration,
323329
'workbenchRequireTime': workbenchLoadDuration,
324330
'globalKeys': this.storageService.storage.getSize(StorageScope.GLOBAL),
325331
'workspaceKeys': this.storageService.storage.getSize(StorageScope.WORKSPACE),
326332
'startupKind': this.lifecycleService.startupKind,
327-
'workspaceIntegrity': workspaceIntegrity,
333+
'integrityWorkspace': workspaceIntegrity,
328334
'storageError': errorStr
329335
});
330336
}
@@ -334,28 +340,42 @@ export class WorkbenchShell extends Disposable {
334340
this.storageService.storage.checkIntegrity(StorageScope.WORKSPACE, false).then(integrity => {
335341
perf.mark('didCheckWorkspaceStorageIntegrity');
336342

337-
workspaceIntegrity = integrity;
343+
if (integrity) {
344+
workspaceIntegrity = integrity;
345+
}
346+
347+
if (this.storageService.storage.hasErrors) {
348+
return; // do not log performance numbers when errors occured
349+
}
350+
351+
if (this.environmentService.verbose || this.environmentService.logStorage) {
352+
return; // do not log when running in verbose mode
353+
}
338354

339355
/* __GDPR__
340-
"sqliteStorageTimers2" : {
356+
"sqliteStorageTimers3" : {
341357
"globalReadTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
358+
"workspaceExistsTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
359+
"workspaceMigrationTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
360+
"workspaceRequireTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
342361
"workspaceReadTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
343-
"localStorageAccessTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
344-
"localStorageReadTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
345-
"workspaceIntegrity" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
362+
"localStorageTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
363+
"integrityWorkspace" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
346364
"workspaceIntegrityCheckTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
347365
"workbenchRequireTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
348366
"globalKeys" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
349367
"workspaceKeys" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true },
350368
"startupKind": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true }
351369
}
352370
*/
353-
this.telemetryService.publicLog('sqliteStorageTimers2', {
371+
this.telemetryService.publicLog('sqliteStorageTimers3', {
354372
'globalReadTime': globalStorageInitDuration,
373+
'workspaceExistsTime': workspaceStorageFileExistsDuration,
374+
'workspaceMigrationTime': workspaceStorageMigrationDuration,
375+
'workspaceRequireTime': workspaceStorageRequireDuration,
355376
'workspaceReadTime': workspaceStorageInitDuration,
356-
'localStorageAccessTime': localStorageAccessDuration,
357-
'localStorageReadTime': localStorageReadDuration,
358-
'workspaceIntegrity': workspaceIntegrity,
377+
'localStorageTime': localStorageDuration,
378+
'integrityWorkspace': workspaceIntegrity,
359379
'workspaceIntegrityCheckTime': perf.getDuration('willCheckWorkspaceStorageIntegrity', 'didCheckWorkspaceStorageIntegrity'),
360380
'workbenchRequireTime': workbenchLoadDuration,
361381
'globalKeys': this.storageService.storage.getSize(StorageScope.GLOBAL),

‎src/vs/workbench/parts/performance/electron-browser/actions.ts‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -33,7 +33,8 @@ class Info {
3333
table['window.loadUrl() => begin to require(workbench.main.js)'] = new Info(metrics.timers.ellapsedWindowLoadToRequire, '[main->renderer]', StartupKindToString(metrics.windowKind));
3434
table['require(workbench.main.js)'] = new Info(metrics.timers.ellapsedRequire, '[renderer]', `cached data: ${(metrics.didUseCachedData ? 'YES' : 'NO')}${nodeModuleLoadTime ? `, node_modules took ${nodeModuleLoadTime}ms` : ''}`);
3535

36-
table['init workspace storage'] = new Info(metrics.timers.ellapsedWorkspaceStorageInit, '[renderer]');
36+
table['require workspace storage'] = new Info(metrics.timers.ellapsedWorkspaceStorageRequire, '[renderer]');
37+
table['require & init workspace storage'] = new Info(metrics.timers.ellapsedWorkspaceStorageInit, '[renderer]');
3738

3839
table['register extensions & spawn extension host'] = new Info(metrics.timers.ellapsedExtensions, '[renderer]');
3940
table['restore viewlet'] = new Info(metrics.timers.ellapsedViewletRestore, '[renderer]', metrics.viewletId);

‎src/vs/workbench/services/timer/electron-browser/timerService.ts‎

Lines changed: 12 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -53,6 +53,7 @@ export interface IMemoryInfo {
5353
"timers.ellapsedExtensions" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "isMeasurement": true },
5454
"timers.ellapsedExtensionsReady" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "isMeasurement": true },
5555
"timers.ellapsedRequire" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "isMeasurement": true },
56+
"timers.ellapsedWorkspaceStorageRequire" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "isMeasurement": true },
5657
"timers.ellapsedWorkspaceStorageInit" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "isMeasurement": true },
5758
"timers.ellapsedViewletRestore" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "isMeasurement": true },
5859
"timers.ellapsedPanelRestore" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "isMeasurement": true },
@@ -194,7 +195,16 @@ export interface IStartupMetrics {
194195
ellapsedWindowLoadToRequire: number;
195196

196197
/**
197-
* The time it took to connect to the workspace storage DB and load the initial set of values.
198+
* The time it took to require the workspace storage DB.
199+
*
200+
* * Happens in the renderer-process
201+
* * Measured with the `willRequireSQLite` and `didRequireSQLite` performance marks.
202+
*/
203+
ellapsedWorkspaceStorageRequire: number;
204+
205+
/**
206+
* The time it took to require the workspace storage DB, connect to it
207+
* and load the initial set of values.
198208
*
199209
* * Happens in the renderer-process
200210
* * Measured with the `willInitWorkspaceStorage` and `didInitWorkspaceStorage` performance marks.
@@ -378,6 +388,7 @@ class TimerService implements ITimerService {
378388
ellapsedWindowLoad: initialStartup ? perf.getDuration('main:appReady', 'main:loadWindow') : undefined,
379389
ellapsedWindowLoadToRequire: perf.getDuration('main:loadWindow', 'willLoadWorkbenchMain'),
380390
ellapsedRequire: perf.getDuration('willLoadWorkbenchMain', 'didLoadWorkbenchMain'),
391+
ellapsedWorkspaceStorageRequire: perf.getDuration('willRequireSQLite', 'didRequireSQLite'),
381392
ellapsedWorkspaceStorageInit: perf.getDuration('willInitWorkspaceStorage', 'didInitWorkspaceStorage'),
382393
ellapsedExtensions: perf.getDuration('willLoadExtensions', 'didLoadExtensions'),
383394
ellapsedEditorRestore: perf.getDuration('willRestoreEditors', 'didRestoreEditors'),

0 commit comments

Comments
 (0)