Skip to content

Commit 7078075

Browse files
eamodioeamodio
committed
Improves logging output
1 parent 77328e2 commit 7078075

File tree

5 files changed

+54
-24
lines changed

5 files changed

+54
-24
lines changed

‎src/git/gitProviderService.ts

Lines changed: 18 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -33,8 +33,8 @@ import { debug, log } from '../system/decorators/log';
3333
import type { Deferrable } from '../system/function';
3434
import { debounce } from '../system/function';
3535
import { count, filter, first, flatMap, groupByFilterMap, groupByMap, join, map, some, sum } from '../system/iterable';
36-
import { Logger } from '../system/logger';
37-
import { getLogScope, setLogScopeExit } from '../system/logger.scope';
36+
import { getLoggableName, Logger } from '../system/logger';
37+
import { getLogScope, setLogScopeExit, startLogScope } from '../system/logger.scope';
3838
import { getScheme, isAbsolute, maybeUri, normalizePath } from '../system/path';
3939
import type { Deferred } from '../system/promise';
4040
import { asSettled, defer, getDeferredPromiseIfPending, getSettledValue } from '../system/promise';
@@ -445,7 +445,8 @@ export class GitProviderService implements Disposable {
445445
...disposables,
446446
provider.onDidChange(() => {
447447
this._etag = Date.now();
448-
Logger.debug(`GitProvider(${id}).onDidChange()`);
448+
using scope = startLogScope(`${getLoggableName(provider)}.onDidChange`, false);
449+
Logger.debug(scope, '');
449450

450451
const { workspaceFolders } = workspace;
451452
if (workspaceFolders?.length) {
@@ -454,7 +455,11 @@ export class GitProviderService implements Disposable {
454455
}),
455456
provider.onDidChangeRepository(async e => {
456457
this._etag = Date.now();
457-
Logger.debug(`GitProvider(${id}).onDidChangeRepository(e=${e.repository.toString()})`);
458+
using scope = startLogScope(
459+
`${getLoggableName(provider)}.onDidChangeRepository(e=${e.repository.toString()})`,
460+
false,
461+
);
462+
Logger.debug(scope, '');
458463

459464
if (e.changed(RepositoryChange.Closed, RepositoryChangeComparisonMode.Any)) {
460465
this.updateContext();
@@ -482,9 +487,11 @@ export class GitProviderService implements Disposable {
482487
provider.onDidCloseRepository(e => {
483488
this._etag = Date.now();
484489
const repository = this._repositories.get(e.uri);
485-
Logger.debug(
486-
`GitProvider(${id}).onDidCloseRepository(e=${repository?.toString() ?? e.uri.toString()})`,
490+
using scope = startLogScope(
491+
`${getLoggableName(provider)}.onDidCloseRepository(e=${e.uri.toString()})`,
492+
false,
487493
);
494+
Logger.debug(scope, `repository=${repository?.toString()}`);
488495

489496
if (repository != null) {
490497
repository.closed = true;
@@ -493,7 +500,11 @@ export class GitProviderService implements Disposable {
493500
provider.onDidOpenRepository(e => {
494501
this._etag = Date.now();
495502
const repository = this._repositories.get(e.uri);
496-
Logger.debug(`GitProvider(${id}).onDidOpenRepository(e=${repository?.toString() ?? e.uri.toString()})`);
503+
using scope = startLogScope(
504+
`${getLoggableName(provider)}.onDidOpenRepository(e=${e.uri.toString()})`,
505+
false,
506+
);
507+
Logger.debug(scope, `repository=${repository?.toString()}`);
497508

498509
if (repository != null) {
499510
repository.closed = false;

‎src/git/models/repository.ts

Lines changed: 7 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,7 @@ import type { Deferrable } from '../../system/function';
1919
import { debounce } from '../../system/function';
2020
import { filter, groupByMap, join, min, some } from '../../system/iterable';
2121
import { getLoggableName, Logger } from '../../system/logger';
22-
import { getLogScope } from '../../system/logger.scope';
22+
import { getLogScope, startLogScope } from '../../system/logger.scope';
2323
import { updateRecordValue } from '../../system/object';
2424
import { basename, normalizePath } from '../../system/path';
2525
import type { GitProviderDescriptor, GitRepositoryProvider } from '../gitProvider';
@@ -351,7 +351,8 @@ export class Repository implements Disposable {
351351
const changed = this._closed !== value;
352352
this._closed = value;
353353
if (changed) {
354-
Logger.debug(`Repository(${this.id}).closed(${value})`);
354+
using scope = startLogScope(`${getLoggableName(this)}.closed`, false);
355+
Logger.debug(scope, `setting closed=${value}`);
355356
this.fireChange(this._closed ? RepositoryChange.Closed : RepositoryChange.Opened);
356357
}
357358
}
@@ -942,7 +943,8 @@ export class Repository implements Disposable {
942943

943944
this._pendingRepoChange = undefined;
944945

945-
Logger.debug(`Repository(${this.id}) firing ${e.toString(true)}`);
946+
using scope = startLogScope(`${getLoggableName(this)}.fireChangeCore`, false);
947+
Logger.debug(scope, `firing ${e.toString(true)}`);
946948
try {
947949
this._onDidChange.fire(e);
948950
} finally {
@@ -991,7 +993,8 @@ export class Repository implements Disposable {
991993
e = { ...e, uris: uris };
992994
}
993995

994-
Logger.debug(`Repository(${this.id}) firing fs changes=${e.uris.map(u => u.fsPath).join(', ')}`);
996+
using scope = startLogScope(`${getLoggableName(this)}.fireChangeCore`, false);
997+
Logger.debug(scope, `firing fs changes=${e.uris.map(u => u.fsPath).join(', ')}`);
995998

996999
this._onDidChangeFileSystem.fire(e);
9971000
}

‎src/plus/gk/authenticationProvider.ts

Lines changed: 11 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -9,8 +9,8 @@ import type { TrackingContext } from '../../constants.telemetry';
99
import type { Container, Environment } from '../../container';
1010
import { CancellationError } from '../../errors';
1111
import { debug } from '../../system/decorators/log';
12-
import { Logger } from '../../system/logger';
13-
import { getLogScope, setLogScopeExit } from '../../system/logger.scope';
12+
import { getLoggableName, Logger } from '../../system/logger';
13+
import { getLogScope, setLogScopeExit, startLogScope } from '../../system/logger.scope';
1414
import { AuthenticationConnection } from './authenticationConnection';
1515
import type { ServerConnection } from './serverConnection';
1616

@@ -203,6 +203,8 @@ export class AccountAuthenticationProvider implements AuthenticationProvider, Di
203203
}
204204

205205
private async checkForUpdates() {
206+
using scope = startLogScope(`${getLoggableName(this)}.checkForUpdates`, false);
207+
206208
const previousSessions = await this._sessionsPromise;
207209
this._sessionsPromise = this.getSessionsFromStorage();
208210
const storedSessions = await this._sessionsPromise;
@@ -225,7 +227,7 @@ export class AccountAuthenticationProvider implements AuthenticationProvider, Di
225227
}
226228

227229
if (added.length || removed.length) {
228-
Logger.debug(`Firing sessions changed event; added=${added.length}, removed=${removed.length}`);
230+
Logger.debug(scope, `firing sessions changed event; added=${added.length}, removed=${removed.length}`);
229231
this._onDidChangeSessions.fire({ added: added, removed: removed, changed: [] });
230232
}
231233
}
@@ -255,6 +257,8 @@ export class AccountAuthenticationProvider implements AuthenticationProvider, Di
255257
}
256258

257259
private async getSessionsFromStorage(): Promise<AuthenticationSession[]> {
260+
using scope = startLogScope(`${getLoggableName(this)}.getSessionsFromStorage`, false);
261+
258262
let storedSessions: StoredSession[];
259263

260264
try {
@@ -271,20 +275,20 @@ export class AccountAuthenticationProvider implements AuthenticationProvider, Di
271275
throw ex;
272276
}
273277
} catch (ex) {
274-
Logger.error(ex, 'Unable to read sessions from storage');
278+
Logger.error(ex, scope, 'Unable to read sessions from storage');
275279
return [];
276280
}
277281

278282
const sessionPromises = storedSessions.map(async (session: StoredSession) => {
279283
const scopesKey = getScopesKey(session.scopes);
280284

281-
Logger.debug(`Read session from storage with scopes=${scopesKey}`);
285+
Logger.debug(scope, `read session from storage with scopes=${scopesKey}`);
282286

283287
let userInfo: { id: string; accountName: string } | undefined;
284288
if (session.account == null) {
285289
try {
286290
userInfo = await this._authConnection.getAccountInfo(session.accessToken);
287-
Logger.debug(`Verified session with scopes=${scopesKey}`);
291+
Logger.debug(scope, `verified session with scopes=${scopesKey}`);
288292
} catch (ex) {
289293
// Remove sessions that return unauthorized response
290294
if (ex.message === 'Unauthorized') return undefined;
@@ -310,7 +314,7 @@ export class AccountAuthenticationProvider implements AuthenticationProvider, Di
310314
.map(p => (p as PromiseFulfilledResult<AuthenticationSession | undefined>).value)
311315
.filter(<T>(p?: T): p is T => Boolean(p));
312316

313-
Logger.debug(`Found ${verifiedSessions.length} verified sessions`);
317+
Logger.debug(scope, `found ${verifiedSessions.length} verified sessions`);
314318
if (verifiedSessions.length !== storedSessions.length) {
315319
await this.storeSessions(verifiedSessions);
316320
}

‎src/views/nodes/fileHistoryNode.ts

Lines changed: 9 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,8 @@ import { memoize } from '../../system/decorators/-webview/memoize';
1212
import { debug } from '../../system/decorators/log';
1313
import { weakEvent } from '../../system/event';
1414
import { filterMap, flatMap, map, uniqueBy } from '../../system/iterable';
15-
import { Logger } from '../../system/logger';
15+
import { getLoggableName, Logger } from '../../system/logger';
16+
import { startLogScope } from '../../system/logger.scope';
1617
import { basename } from '../../system/path';
1718
import type { FileHistoryView } from '../fileHistoryView';
1819
import { SubscribeableViewNode } from './abstract/subscribeableViewNode';
@@ -217,7 +218,8 @@ export class FileHistoryNode
217218
return;
218219
}
219220

220-
Logger.debug(`FileHistoryNode.onRepositoryChanged(${e.toString()}); triggering node refresh`);
221+
using scope = startLogScope(`${getLoggableName(this)}.onRepositoryChanged(e=${e.toString()})`, false);
222+
Logger.debug(scope, 'triggering node refresh');
221223

222224
void this.triggerChange(true);
223225
}
@@ -229,7 +231,11 @@ export class FileHistoryNode
229231
return;
230232
}
231233

232-
Logger.debug(`FileHistoryNode.onFileSystemChanged(${this.uri.toString(true)}); triggering node refresh`);
234+
using scope = startLogScope(
235+
`${getLoggableName(this)}.onFileSystemChanged(e=${this.uri.toString(true)})`,
236+
false,
237+
);
238+
Logger.debug(scope, 'triggering node refresh');
233239

234240
void this.triggerChange(true);
235241
}

‎src/views/nodes/lineHistoryNode.ts

Lines changed: 9 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -13,7 +13,8 @@ import { memoize } from '../../system/decorators/-webview/memoize';
1313
import { debug } from '../../system/decorators/log';
1414
import { weakEvent } from '../../system/event';
1515
import { filterMap } from '../../system/iterable';
16-
import { Logger } from '../../system/logger';
16+
import { getLoggableName, Logger } from '../../system/logger';
17+
import { startLogScope } from '../../system/logger.scope';
1718
import type { FileHistoryView } from '../fileHistoryView';
1819
import type { LineHistoryView } from '../lineHistoryView';
1920
import { SubscribeableViewNode } from './abstract/subscribeableViewNode';
@@ -220,15 +221,20 @@ export class LineHistoryNode
220221
return;
221222
}
222223

223-
Logger.debug(`LineHistoryNode.onRepositoryChanged(${e.toString()}); triggering node refresh`);
224+
using scope = startLogScope(`${getLoggableName(this)}.onRepositoryChanged(e=${e.toString()})`, false);
225+
Logger.debug(scope, 'triggering node refresh');
224226

225227
void this.triggerChange(true);
226228
}
227229

228230
private onFileSystemChanged(e: RepositoryFileSystemChangeEvent) {
229231
if (!e.uris.some(uri => uri.toString() === this.uri.toString())) return;
230232

231-
Logger.debug(`LineHistoryNode.onFileSystemChanged(${this.uri.toString(true)}); triggering node refresh`);
233+
using scope = startLogScope(
234+
`${getLoggableName(this)}.onFileSystemChanged(e=${this.uri.toString(true)})`,
235+
false,
236+
);
237+
Logger.debug(scope, 'triggering node refresh');
232238

233239
void this.triggerChange(true);
234240
}

0 commit comments

Comments
 (0)