Add telemetry for download, extract, and analyze. #2597

d3r3kk · 2018-09-15T05:22:58Z

Fixes #2461 (alternate fix to PR #2593)

Capture telemetry using decorators to methods, minimizing change, improving maintainability (thanks @DonJayamanne!)
Add success/fail props modifier func to captureTelemetry to better handle failure telemetry emissions.
Potential correction of New language server seems to be frozen at analyzing workspace for more than 30 minutes #2297 and related (I believe Progress reporting does not always clear when analysis completes python-language-server#94 is corrected here as well).
Pull request represents a single change (i.e. not fixing disparate/unrelated things in a single PR)
Title summarizes what is changing
Has a news entry file (remember to thank yourself!)
~~Has unit tests & system/integration tests (needed for progress reporter, telemetry tests are likely unnecessary unless someone tells me differently).~~ We will need to alter the code (make LanguageClient and Progress accessible via DI - not appropriate for this PR).
Remove pre-success, pre-error, telemetry emission functions, replace with object member-setter.
Remove 2297 fix from this PR and create new one.
~~Any new/changed dependencies in package.json are pinned (e.g. "1.2.3", not "^1.2.3" for the specified version)~~
~~package-lock.json has been regenerated by running npm install (if dependencies have changed)~~

d3r3kk · 2018-09-15T05:24:26Z

src/client/activation/progress.ts

@@ -19,7 +26,14 @@ export class ProgressReporting {
    });

    this.languageClient.onNotification('python/beginProgress', async _ => {
+      if (this.progressDeferred) { // if we restarted, no worries as reporting will still funnel to the same place.


This is the fix for #2297 and related...

For #2297 (while most of the problem is not here, restart is rare) you need to track 'stateChange' on the language client. When it gets to 'stopped' LS has terminated.

Cool! Thanks for the tip. I'll move this code to another PR that we can review separately and cover all the appropriate cases.

@MikhailArkhipov please see #2606

d3r3kk · 2018-09-15T05:29:00Z

Note: Also snuck my PVSC_EXTENSION_ID constant into this PR...

DonJayamanne · 2018-09-15T05:24:24Z

src/client/activation/downloader.ts

+        PYTHON_LANGUAGE_SERVER_DOWNLOADED,
+        {},
+        true,
+        (props?: LanguageServerTelemetry) => props ? props.success = true : undefined


Change second argument to {success:true}
And remove this last argument , no need of callback

Ok, I can do that - but let's discuss a bit first.

What if the TelemetryProperties instance handed to the decorator doesn't have a success field within?

What if I want to do other things than just set properties on the telemetry? Or set a field called something other than success accordingly?

Actually, now that you have me thinking, what about instead of a callback that gets a reference to the properties only, the beforeFailedEmit gets both the properties and the error?

Adding additional properties is easy. Today you just need to add a type deffinition. You have already done that. I have added type deffinition to the twenty to ensure we don't add anything, this way we know exactly what's sent in the telemetry, else we have to go around looking at the code base to find the telemetry properties.

What if I want to do other things than just set properties on the telemetry? Or set a field called something other than success accordingly?

Like what? We haven't had the need for such things. All we need with telemetry is send data.
Let's not plan for tomorrow and overload the purpose of the decoratotor. Just send telemetry. If you want pre and post method execution, then you need another decorator, not this.

Yep, I buy that, I'll make the change.

Just to pile on here, let's not build things we don't need. Even things we do need we shouldn't build until we need them unless they have major architectural implications. Less is more.

DonJayamanne · 2018-09-15T05:25:52Z

src/client/telemetry/index.ts

+    properties?: TelemetryProperties,
+    captureDuration: boolean = true,
+    // tslint:disable-next-line:no-any
+    beforeSuccessEmit?: (props?: any) => void,


We don't need these two new parameters. Just remove the last two parameters.
Remove the 3rd and 4th arguments.

DonJayamanne · 2018-09-15T05:27:59Z

src/client/telemetry/index.ts

@@ -48,11 +56,17 @@ export function captureTelemetry(eventName: string, properties?: TelemetryProper
                // tslint:disable-next-line:prefer-type-cast
                (result as Promise<void>)
                    .then(data => {
+                        if (beforeSuccessEmit) {


Please remove this if condition and this new code.

DonJayamanne · 2018-09-15T05:29:27Z

src/client/telemetry/index.ts

                        sendTelemetryEvent(eventName, stopWatch.elapsedTime, properties);
                        return data;
                    })
                    // tslint:disable-next-line:promise-function-async
                    .catch(ex => {
+                        if (beforeFailEmit) {


Please remove this if condition and this code. Change as follows:

properties = properties ? properties : {}; properties.success = false;

I cannot quite understand this exactly.

What happens when properties is not null, and was not given with a success member?

For instance, what happens when this comes from the decorator on CodeExecutionManager::executeFileInterTerminal?

That use of TelemetryProperties is using the union-ed type CodeExecutionTelemetry and has no success field.

properties = properties ? properties : {}; if ((<LanguageServerTelemetry>properties).success) { (<LanguageServerTelemetry>properties).success = false; }

Reference: Type Guards and Differentiating Types

Indeed, I will have to do the type-check/type-cast it would seem:

Just change as follows:

properties = (properties ? properties : {}) as any; if (properties.success !== undefined) { properties.success = false; }

Check for undefined

Yeah, I don't think we want to do this. Assuming that success is always false when an exception is thrown (or Promise rejected) in this one case isn't necessarily going to be the right path for the next TelemetryProperties type we add with a success field.

I want to go back to doing something more explicit in the downloader/languageServer themselves instead.

DonJayamanne · 2018-09-15T05:31:23Z

src/client/activation/languageServer.ts

@@ -140,6 +147,12 @@ export class LanguageServerExtensionActivator implements IExtensionActivator {
        (this.configuration.getSettings() as PythonSettings).removeListener('change', this.onSettingsChanged.bind(this));
    }

+    @captureTelemetry(
+        PYTHON_LANGUAGE_SERVER_STARTUP,
+        this.languageServerStartupTelemetry,


Please do not access this inside the decoratotor.
Just change second parameter to {success: true}

Is this not valid in a decorator? Perhaps a static variable then (gross...) or I'll just do your suggestion. Loose typing like this can confuse me at times...

We don't need this, all we need is a constant object.

Loose typing like this can confuse me at times...

It's not loose typing at all, you can't set the second argument to anything, you'll get to compilation errors, meaning it's strongly typed.

Once again it is not at all loosely typed.

See the definition for the function, check the second argument:

export function captureTelemetry( eventName: string, properties?: TelemetryProperties,

DonJayamanne · 2018-09-15T05:31:45Z

src/client/activation/languageServer.ts

+        PYTHON_LANGUAGE_SERVER_STARTUP,
+        this.languageServerStartupTelemetry,
+        true,
+        (props?: LanguageServerTelemetry) => props ? props.success = true : undefined


Please remove this last two argument, not necessary.

DonJayamanne · 2018-09-15T05:33:45Z

src/client/activation/downloader.ts

@@ -28,6 +34,11 @@ export const DownloadLinks = {
 };

 export class LanguageServerDownloader {
+    //tslint:disable-next-line:no-unused-variable
+    private lsDownloadTelemetry: LanguageServerTelemetry = {};


Please remove

DonJayamanne · 2018-09-15T05:33:55Z

src/client/activation/downloader.ts

+    //tslint:disable-next-line:no-unused-variable
+    private lsDownloadTelemetry: LanguageServerTelemetry = {};
+    //tslint:disable-next-line:no-unused-variable
+    private lsExtractTelemetry: LanguageServerTelemetry = {};


Please remove

DonJayamanne · 2018-09-15T05:34:48Z

src/client/activation/downloader.ts

+        PYTHON_LANGUAGE_SERVER_EXTRACTED,
+        this.languageServerStartupTelemetry,
+        true,
+        (props?: LanguageServerTelemetry) => props ? props.success = true : undefined


Change second argument to {success:true}
And remove this last argument , no need of callback

DonJayamanne · 2018-09-15T05:36:24Z

src/client/activation/progress.ts

      this.progressDeferred = createDeferred<void>();
+      this.progressTimer = new StopWatch();
+      this.progressTimeout = setTimeout(this.handleTimeout, this.ANALYSIS_TIMEOUT_MS);
+


Change to setTimeout(this.handleTimeout.bind(this), .....
You need to preserve callback scope.

Cool - that callback scope still isn't always clear to me, thanks for catching this.

Fixes microsoft#2461 (alternate fix to PR microsoft#2593) - Capture telemetry surrounds methods, minimizing change - Telemetry type can be altered with less code later. - Add success/fail props modifyer func to `captureTelemetry`

- LanguageServerTelemetry is simpler and succinct enough for this use

- I believe this might fix microsoft#2297 (and related issues) - Calling 'beginProgress' from LS causes progress reporting to not get cleaned up properly. - Related fix for microsoft/python-language-server#94

- versus hard-coding the string in multiple places.

- to avoid pollute the generic nature of the decorator, it's best to make this solution explicit

MikhailArkhipov · 2018-09-17T23:10:12Z

src/client/activation/downloader.ts

-            if (localTempFilePath.length > 0) {
-                await this.fs.deleteFile(localTempFilePath);
-            }
+            sendTelemetryEvent('DEREK2', timer.elapsedTime, { success: success === true });


Apologies - this is a WIP at the moment...

d3r3kk · 2018-09-17T23:35:51Z

@DonJayamanne please re-review.

DonJayamanne · 2018-09-18T00:49:05Z

src/client/activation/downloader.ts

        try {
            localTempFilePath = await this.downloadFile(downloadUri, 'Downloading Microsoft Python Language Server... ');
+        } catch (err) {


Why did we go with this approach instead of the decorator?

As you can see there's some duplication of code..

Because the decorator emits telemetry, and adds timing info. It does not allow for state changes in property values without increasing complexity of the decorator function. I couldn't come up with an appropriate reason for the added complexity.

DonJayamanne · 2018-09-18T00:55:23Z

src/client/activation/progress.ts

+  private progressTimer?: StopWatch;
+  // tslint:disable-next-line:no-unused-variable
+  private progressTimeout?: NodeJS.Timer;
+  private ANALYSIS_TIMEOUT_MS: number = 60000;


This needs to be a constant, not a member.

Agreed. I will make the change. Thanks for calling this out!

d3r3kk commented Sep 15, 2018

View reviewed changes

d3r3kk mentioned this pull request Sep 15, 2018

Add telemetry for Language Server download, extraction, and analysis (startup) time. #2593

Closed

13 tasks

DonJayamanne requested changes Sep 15, 2018

View reviewed changes

d3r3kk added 8 commits September 17, 2018 09:58

Remove all .venv*/ folders in .gitignore

7deb17e

Add telemetry for download, extract, and analyze.

5334b59

Fixes microsoft#2461 (alternate fix to PR microsoft#2593) - Capture telemetry surrounds methods, minimizing change - Telemetry type can be altered with less code later. - Add success/fail props modifyer func to `captureTelemetry`

Simplify telemetry properties.

3f04848

- LanguageServerTelemetry is simpler and succinct enough for this use

Add telemetry collection for analysis reporting complete.

44c9396

- I believe this might fix microsoft#2297 (and related issues) - Calling 'beginProgress' from LS causes progress reporting to not get cleaned up properly. - Related fix for microsoft/python-language-server#94

Add news file

9ea1c39

Add news file for 2297 as well

fa2376f

Add constant for the extension ID

2f6cd5f

- versus hard-coding the string in multiple places.

Use constant for extension ID

4fd9348

d3r3kk force-pushed the telemetry_alt_ext branch from dcf92cc to 4fd9348 Compare September 17, 2018 16:58

Remove use of captureTelemetry

0dd4175

- to avoid pollute the generic nature of the decorator, it's best to make this solution explicit

MikhailArkhipov reviewed Sep 17, 2018

View reviewed changes

d3r3kk changed the title ~~Add telemetry for download, extract, and analyze.~~ [WIP] Add telemetry for download, extract, and analyze. Sep 17, 2018

Simplify fixups a bit further.

ec73eb4

DonJayamanne approved these changes Sep 18, 2018

View reviewed changes

PR suggestion fixup.

c211f0f

d3r3kk changed the title ~~[WIP] Add telemetry for download, extract, and analyze.~~ Add telemetry for download, extract, and analyze. Sep 18, 2018

d3r3kk merged commit 581c18d into microsoft:master Sep 18, 2018

d3r3kk deleted the telemetry_alt_ext branch September 18, 2018 16:35

lock bot locked as resolved and limited conversation to collaborators Jul 31, 2019

Add telemetry for download, extract, and analyze. #2597

Add telemetry for download, extract, and analyze. #2597

Conversation

d3r3kk commented Sep 15, 2018 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

d3r3kk Sep 17, 2018 • edited Loading

Choose a reason for hiding this comment

d3r3kk commented Sep 15, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

DonJayamanne Sep 15, 2018 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

d3r3kk Sep 17, 2018 • edited Loading

Choose a reason for hiding this comment

d3r3kk Sep 17, 2018 • edited Loading

Choose a reason for hiding this comment

DonJayamanne Sep 17, 2018 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

d3r3kk commented Sep 17, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

d3r3kk commented Sep 15, 2018 •

edited

Loading

d3r3kk Sep 17, 2018 •

edited

Loading

DonJayamanne Sep 15, 2018 •

edited

Loading

d3r3kk Sep 17, 2018 •

edited

Loading

d3r3kk Sep 17, 2018 •

edited

Loading

DonJayamanne Sep 17, 2018 •

edited

Loading