Skip to content

Commit 5ab1b73

Browse files
authored
Capture request timings in language server client middleware (microsoft#10419)
1 parent 9c72a7f commit 5ab1b73

9 files changed

Lines changed: 254 additions & 12 deletions

File tree

experiments.json

Lines changed: 24 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -112,5 +112,29 @@
112112
"salt": "WebHostNotebook",
113113
"min": 0,
114114
"max": 100
115+
},
116+
{
117+
"name": "CollectLSRequestTiming - experiment",
118+
"salt": "CollectLSRequestTiming",
119+
"min": 0,
120+
"max": 10
121+
},
122+
{
123+
"name": "CollectLSRequestTiming - control",
124+
"salt": "CollectLSRequestTiming",
125+
"min": 10,
126+
"max": 100
127+
},
128+
{
129+
"name": "CollectNodeLSRequestTiming - experiment",
130+
"salt": "CollectNodeLSRequestTiming",
131+
"min": 0,
132+
"max": 100
133+
},
134+
{
135+
"name": "CollectNodeLSRequestTiming - control",
136+
"salt": "CollectNodeLSRequestTiming",
137+
"min": 0,
138+
"max": 0
115139
}
116140
]

package.json

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1520,6 +1520,8 @@
15201520
"AA_testing - experiment",
15211521
"WebHostNotebook - experiment",
15221522
"UseTerminalToGetActivatedEnvVars - experiment",
1523+
"CollectLSRequestTiming - experiment",
1524+
"CollectNodeLSRequestTiming - experiment",
15231525
"All"
15241526
]
15251527
},
@@ -1540,6 +1542,8 @@
15401542
"AA_testing - experiment",
15411543
"WebHostNotebook - experiment",
15421544
"UseTerminalToGetActivatedEnvVars - experiment",
1545+
"CollectLSRequestTiming - experiment",
1546+
"CollectNodeLSRequestTiming - experiment",
15431547
"All"
15441548
]
15451549
},

src/client/activation/languageClientMiddleware.ts

Lines changed: 145 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@ import {
99
Command,
1010
CompletionContext,
1111
CompletionItem,
12+
Declaration as VDeclaration,
1213
Definition,
1314
DefinitionLink,
1415
Diagnostic,
@@ -18,6 +19,7 @@ import {
1819
FormattingOptions,
1920
Location,
2021
Position,
22+
Position as VPosition,
2123
ProviderResult,
2224
Range,
2325
SignatureHelp,
@@ -51,14 +53,58 @@ import {
5153
ResolveDocumentLinkSignature
5254
} from 'vscode-languageclient';
5355

56+
import { ProvideDeclarationSignature } from 'vscode-languageclient/lib/declaration';
5457
import { HiddenFilePrefix } from '../common/constants';
55-
import { IPythonExtensionBanner } from '../common/types';
58+
import { CollectLSRequestTiming, CollectNodeLSRequestTiming } from '../common/experimentGroups';
59+
import { IExperimentsManager, IPythonExtensionBanner } from '../common/types';
60+
import { StopWatch } from '../common/utils/stopWatch';
61+
import { sendTelemetryEvent } from '../telemetry';
62+
import { EventName } from '../telemetry/constants';
63+
import { LanguageServerType } from './types';
64+
65+
// Only send 100 events per hour.
66+
const globalDebounce = 1000 * 60 * 60;
67+
const globalLimit = 100;
68+
69+
// For calls that are more likely to happen during a session (hover, completion, document symbols).
70+
const debounceFrequentCall = 1000 * 60 * 5;
71+
72+
// For calls that are less likely to happen during a session (go-to-def, workspace symbols).
73+
const debounceRareCall = 1000 * 60;
5674

5775
export class LanguageClientMiddleware implements Middleware {
76+
// These are public so that the captureTelemetryForLSPMethod decorator can access them.
77+
public readonly eventName: EventName | undefined;
78+
public readonly lastCaptured = new Map<string, number>();
79+
public nextWindow: number = 0;
80+
public eventCount: number = 0;
81+
5882
private connected = false; // Default to not forwarding to VS code.
5983

60-
public constructor(private readonly surveyBanner: IPythonExtensionBanner) {
84+
public constructor(
85+
private readonly surveyBanner: IPythonExtensionBanner,
86+
experimentsManager: IExperimentsManager,
87+
serverType: LanguageServerType,
88+
public readonly serverVersion?: string
89+
) {
6190
this.handleDiagnostics = this.handleDiagnostics.bind(this); // VS Code calls function without context.
91+
92+
let group: { experiment: string; control: string } | undefined;
93+
94+
if (serverType === LanguageServerType.Microsoft) {
95+
this.eventName = EventName.PYTHON_LANGUAGE_SERVER_REQUEST;
96+
group = CollectLSRequestTiming;
97+
} else if (serverType === LanguageServerType.Node) {
98+
this.eventName = EventName.PYTHON_NODE_SERVER_REQUEST;
99+
group = CollectNodeLSRequestTiming;
100+
} else {
101+
return;
102+
}
103+
104+
if (!experimentsManager.inExperiment(group.experiment)) {
105+
this.eventName = undefined;
106+
experimentsManager.sendTelemetryIfInExperiment(group.control);
107+
}
62108
}
63109

64110
public connect() {
@@ -69,6 +115,7 @@ export class LanguageClientMiddleware implements Middleware {
69115
this.connected = false;
70116
}
71117

118+
@captureTelemetryForLSPMethod('textDocument/completion', debounceFrequentCall)
72119
public provideCompletionItem(
73120
document: TextDocument,
74121
position: Position,
@@ -82,6 +129,7 @@ export class LanguageClientMiddleware implements Middleware {
82129
}
83130
}
84131

132+
@captureTelemetryForLSPMethod('textDocument/hover', debounceFrequentCall)
85133
public provideHover(
86134
document: TextDocument,
87135
position: Position,
@@ -104,6 +152,7 @@ export class LanguageClientMiddleware implements Middleware {
104152
}
105153
}
106154

155+
@captureTelemetryForLSPMethod('completionItem/resolve', debounceFrequentCall)
107156
public resolveCompletionItem(
108157
item: CompletionItem,
109158
token: CancellationToken,
@@ -113,6 +162,8 @@ export class LanguageClientMiddleware implements Middleware {
113162
return next(item, token);
114163
}
115164
}
165+
166+
@captureTelemetryForLSPMethod('textDocument/signatureHelp', debounceFrequentCall)
116167
public provideSignatureHelp(
117168
document: TextDocument,
118169
position: Position,
@@ -123,6 +174,8 @@ export class LanguageClientMiddleware implements Middleware {
123174
return next(document, position, token);
124175
}
125176
}
177+
178+
@captureTelemetryForLSPMethod('textDocument/definition', debounceRareCall)
126179
public provideDefinition(
127180
document: TextDocument,
128181
position: Position,
@@ -133,6 +186,8 @@ export class LanguageClientMiddleware implements Middleware {
133186
return next(document, position, token);
134187
}
135188
}
189+
190+
@captureTelemetryForLSPMethod('textDocument/references', debounceRareCall)
136191
public provideReferences(
137192
document: TextDocument,
138193
position: Position,
@@ -146,6 +201,7 @@ export class LanguageClientMiddleware implements Middleware {
146201
return next(document, position, options, token);
147202
}
148203
}
204+
149205
public provideDocumentHighlights(
150206
document: TextDocument,
151207
position: Position,
@@ -156,6 +212,8 @@ export class LanguageClientMiddleware implements Middleware {
156212
return next(document, position, token);
157213
}
158214
}
215+
216+
@captureTelemetryForLSPMethod('textDocument/documentSymbol', debounceFrequentCall)
159217
public provideDocumentSymbols(
160218
document: TextDocument,
161219
token: CancellationToken,
@@ -165,6 +223,8 @@ export class LanguageClientMiddleware implements Middleware {
165223
return next(document, token);
166224
}
167225
}
226+
227+
@captureTelemetryForLSPMethod('workspace/symbol', debounceRareCall)
168228
public provideWorkspaceSymbols(
169229
query: string,
170230
token: CancellationToken,
@@ -174,6 +234,8 @@ export class LanguageClientMiddleware implements Middleware {
174234
return next(query, token);
175235
}
176236
}
237+
238+
@captureTelemetryForLSPMethod('textDocument/codeAction', debounceFrequentCall)
177239
public provideCodeActions(
178240
document: TextDocument,
179241
range: Range,
@@ -185,6 +247,8 @@ export class LanguageClientMiddleware implements Middleware {
185247
return next(document, range, context, token);
186248
}
187249
}
250+
251+
@captureTelemetryForLSPMethod('textDocument/codeLens', debounceFrequentCall)
188252
public provideCodeLenses(
189253
document: TextDocument,
190254
token: CancellationToken,
@@ -194,6 +258,8 @@ export class LanguageClientMiddleware implements Middleware {
194258
return next(document, token);
195259
}
196260
}
261+
262+
@captureTelemetryForLSPMethod('codeLens/resolve', debounceFrequentCall)
197263
public resolveCodeLens(
198264
codeLens: CodeLens,
199265
token: CancellationToken,
@@ -203,6 +269,7 @@ export class LanguageClientMiddleware implements Middleware {
203269
return next(codeLens, token);
204270
}
205271
}
272+
206273
public provideDocumentFormattingEdits(
207274
document: TextDocument,
208275
options: FormattingOptions,
@@ -213,6 +280,7 @@ export class LanguageClientMiddleware implements Middleware {
213280
return next(document, options, token);
214281
}
215282
}
283+
216284
public provideDocumentRangeFormattingEdits(
217285
document: TextDocument,
218286
range: Range,
@@ -224,6 +292,7 @@ export class LanguageClientMiddleware implements Middleware {
224292
return next(document, range, options, token);
225293
}
226294
}
295+
227296
public provideOnTypeFormattingEdits(
228297
document: TextDocument,
229298
position: Position,
@@ -236,6 +305,8 @@ export class LanguageClientMiddleware implements Middleware {
236305
return next(document, position, ch, options, token);
237306
}
238307
}
308+
309+
@captureTelemetryForLSPMethod('textDocument/rename', debounceRareCall)
239310
public provideRenameEdits(
240311
document: TextDocument,
241312
position: Position,
@@ -247,6 +318,8 @@ export class LanguageClientMiddleware implements Middleware {
247318
return next(document, position, newName, token);
248319
}
249320
}
321+
322+
@captureTelemetryForLSPMethod('textDocument/prepareRename', debounceRareCall)
250323
public prepareRename(
251324
document: TextDocument,
252325
position: Position,
@@ -263,6 +336,7 @@ export class LanguageClientMiddleware implements Middleware {
263336
return next(document, position, token);
264337
}
265338
}
339+
266340
public provideDocumentLinks(
267341
document: TextDocument,
268342
token: CancellationToken,
@@ -272,6 +346,7 @@ export class LanguageClientMiddleware implements Middleware {
272346
return next(document, token);
273347
}
274348
}
349+
275350
public resolveDocumentLink(
276351
link: DocumentLink,
277352
token: CancellationToken,
@@ -281,4 +356,72 @@ export class LanguageClientMiddleware implements Middleware {
281356
return next(link, token);
282357
}
283358
}
359+
360+
@captureTelemetryForLSPMethod('textDocument/declaration', debounceRareCall)
361+
public provideDeclaration(
362+
document: TextDocument,
363+
position: VPosition,
364+
token: CancellationToken,
365+
next: ProvideDeclarationSignature
366+
): ProviderResult<VDeclaration> {
367+
if (this.connected) {
368+
return next(document, position, token);
369+
}
370+
}
371+
}
372+
373+
function captureTelemetryForLSPMethod(method: string, debounceMilliseconds: number) {
374+
// tslint:disable-next-line:no-function-expression no-any
375+
return function(_target: Object, _propertyKey: string, descriptor: TypedPropertyDescriptor<any>) {
376+
const originalMethod = descriptor.value;
377+
378+
// tslint:disable-next-line:no-any
379+
descriptor.value = function(this: LanguageClientMiddleware, ...args: any[]) {
380+
const eventName = this.eventName;
381+
if (!eventName) {
382+
return originalMethod.apply(this, args);
383+
}
384+
385+
const now = Date.now();
386+
387+
if (now > this.nextWindow) {
388+
// Past the end of the last window, reset.
389+
this.nextWindow = now + globalDebounce;
390+
this.eventCount = 0;
391+
} else if (this.eventCount >= globalLimit) {
392+
// Sent too many events in this window, don't send.
393+
return originalMethod.apply(this, args);
394+
}
395+
396+
const lastCapture = this.lastCaptured.get(method);
397+
if (lastCapture && now - lastCapture < debounceMilliseconds) {
398+
return originalMethod.apply(this, args);
399+
}
400+
401+
this.lastCaptured.set(method, now);
402+
this.eventCount += 1;
403+
404+
const properties = {
405+
lsVersion: this.serverVersion || 'unknown',
406+
method: method
407+
};
408+
409+
const stopWatch = new StopWatch();
410+
// tslint:disable-next-line:no-unsafe-any
411+
const result = originalMethod.apply(this, args);
412+
413+
// tslint:disable-next-line:no-unsafe-any
414+
if (result && typeof result.then === 'function') {
415+
(result as Thenable<void>).then(() => {
416+
sendTelemetryEvent(eventName, stopWatch.elapsedTime, properties);
417+
});
418+
} else {
419+
sendTelemetryEvent(eventName, stopWatch.elapsedTime, properties);
420+
}
421+
422+
return result;
423+
};
424+
425+
return descriptor;
426+
};
284427
}

0 commit comments

Comments
 (0)