Skip to content

Modify telemetry to contain trigger time as property #22941

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 5 commits into from
Feb 21, 2024
Merged

Modify telemetry to contain trigger time as property #22941

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
d38561e
Modify telemetry to contain trigger time as property
Feb 20, 2024
7020d70
Also add duration
Feb 20, 2024
f7454cf
update name
Feb 20, 2024
026554a
send first session as part of editor_load
Feb 21, 2024
86e1de0
safely calculate it
Feb 21, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion src/client/common/persistentState.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -108,7 +108,7 @@ export class PersistentState<T> implements IPersistentState<T> {
export const GLOBAL_PERSISTENT_KEYS_DEPRECATED = 'PYTHON_EXTENSION_GLOBAL_STORAGE_KEYS';
export const WORKSPACE_PERSISTENT_KEYS_DEPRECATED = 'PYTHON_EXTENSION_WORKSPACE_STORAGE_KEYS';

const GLOBAL_PERSISTENT_KEYS = 'PYTHON_GLOBAL_STORAGE_KEYS';
export const GLOBAL_PERSISTENT_KEYS = 'PYTHON_GLOBAL_STORAGE_KEYS';
const WORKSPACE_PERSISTENT_KEYS = 'PYTHON_WORKSPACE_STORAGE_KEYS';
type KeysStorageType = 'global' | 'workspace';
export type KeysStorage = { key: string; defaultValue: unknown };
Expand Down
6 changes: 4 additions & 2 deletions src/client/extension.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -46,6 +46,7 @@ import { WorkspaceService } from './common/application/workspace';
import { disposeAll } from './common/utils/resourceLifecycle';
import { ProposedExtensionAPI } from './proposedApiTypes';
import { buildProposedApi } from './proposedApi';
import { GLOBAL_PERSISTENT_KEYS } from './common/persistentState';

durations.codeLoadingTime = stopWatch.elapsedTime;

Expand All @@ -62,7 +63,9 @@ export async function activate(context: IExtensionContext): Promise<PythonExtens
let api: PythonExtension;
let ready: Promise<void>;
let serviceContainer: IServiceContainer;
let isFirstSession: boolean | undefined;
try {
isFirstSession = context.globalState.get(GLOBAL_PERSISTENT_KEYS, []).length === 0;
const workspaceService = new WorkspaceService();
context.subscriptions.push(
workspaceService.onDidGrantWorkspaceTrust(async () => {
Expand All @@ -79,8 +82,7 @@ export async function activate(context: IExtensionContext): Promise<PythonExtens
}
// Send the "success" telemetry only if activation did not fail.
// Otherwise Telemetry is send via the error handler.

sendStartupTelemetry(ready, durations, stopWatch, serviceContainer)
sendStartupTelemetry(ready, durations, stopWatch, serviceContainer, isFirstSession)
// Run in the background.
.ignoreErrors();
return api;
Expand Down
4 changes: 3 additions & 1 deletion src/client/languageServer/watcher.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -178,7 +178,9 @@ export class LanguageServerWatcher implements IExtensionActivationService, ILang
// Start the language server.
if (startupStopWatch) {
// It means that startup is triggering this code, track time it takes since startup to activate this code.
sendTelemetryEvent(EventName.LANGUAGE_SERVER_TRIGGER_DURATION, startupStopWatch.elapsedTime);
sendTelemetryEvent(EventName.LANGUAGE_SERVER_TRIGGER_TIME, startupStopWatch.elapsedTime, {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

would it be tricky to make isFirstSession a property of this event? 🙈 if it is nvm, this works well. It'd just simplify the metric creation

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I mentioned it to Courtney but My reason for adding FIRST_SESSION as a separate telemetry, rather than including it in EDITOR_LOAD is that EDITOR_LOAD will be sent every session, as opposed to FIRST_SESSION, so I figured we might be saving some bandwidth.

But I can add it to EDITOR_LOAD if that's preferred, just let me know :)

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Luciana mentioned it might be easier to create/filter metrics if this was a property in the editor_load and trigger_time events so if it is the first session we can query firstSession = True or something like that in those events.

I guess how difficult would it be to add as a property? If it would be a significant lift we can still work with it as designed.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No problem, I've added it as part of EDITOR_LOAD

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we should also add it to the language_server_trigger_time event as well so we can compare that startup time on first session too.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That'd be a bit tough, to pass that info all the way down to where language_server_trigger_time is sent. The way I'm thinking is that we filter the first session out using editor load for which we check the value of language_server_trigger_time.

triggerTime: startupStopWatch.elapsedTime,
Copy link
Member

@cwebster-99 cwebster-99 Feb 21, 2024 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is also passed as a Measure. We could remove this later so long as it shows up correctly as a Measure since Properties as stored as strings.

});
}
await languageServerExtensionManager.startLanguageServer(lsResource, interpreter);

Expand Down
11 changes: 8 additions & 3 deletions src/client/startupTelemetry.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@ export async function sendStartupTelemetry(
durations: IStartupDurations,
stopWatch: IStopWatch,
serviceContainer: IServiceContainer,
isFirstSession: boolean,
) {
if (isTestExecution()) {
return;
Expand All @@ -30,7 +31,7 @@ export async function sendStartupTelemetry(
try {
await activatedPromise;
durations.totalNonBlockingActivateTime = stopWatch.elapsedTime - durations.startActivateTime;
const props = await getActivationTelemetryProps(serviceContainer);
const props = await getActivationTelemetryProps(serviceContainer, isFirstSession);
sendTelemetryEvent(EventName.EDITOR_LOAD, durations, props);
} catch (ex) {
traceError('sendStartupTelemetry() failed.', ex);
Expand Down Expand Up @@ -76,7 +77,10 @@ export function hasUserDefinedPythonPath(resource: Resource, serviceContainer: I
: false;
}

async function getActivationTelemetryProps(serviceContainer: IServiceContainer): Promise<EditorLoadTelemetry> {
async function getActivationTelemetryProps(
serviceContainer: IServiceContainer,
isFirstSession?: boolean,
): Promise<EditorLoadTelemetry> {
// TODO: Not all of this data is showing up in the database...

// TODO: If any one of these parts fails we send no info. We should
Expand All @@ -88,7 +92,7 @@ async function getActivationTelemetryProps(serviceContainer: IServiceContainer):
const terminalHelper = serviceContainer.get<ITerminalHelper>(ITerminalHelper);
const terminalShellType = terminalHelper.identifyTerminalShell();
if (!workspaceService.isTrusted) {
return { workspaceFolderCount, terminal: terminalShellType };
return { workspaceFolderCount, terminal: terminalShellType, isFirstSession };
}
const interpreterService = serviceContainer.get<IInterpreterService>(IInterpreterService);
const mainWorkspaceUri = workspaceService.workspaceFolders?.length
Expand Down Expand Up @@ -132,5 +136,6 @@ async function getActivationTelemetryProps(serviceContainer: IServiceContainer):
usingUserDefinedInterpreter,
usingGlobalInterpreter,
appName,
isFirstSession,
};
}
2 changes: 1 addition & 1 deletion src/client/telemetry/constants.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -64,7 +64,7 @@ export enum EventName {
EXTENSION_SURVEY_PROMPT = 'EXTENSION_SURVEY_PROMPT',

LANGUAGE_SERVER_ENABLED = 'LANGUAGE_SERVER.ENABLED',
LANGUAGE_SERVER_TRIGGER_DURATION = 'LANGUAGE_SERVER.TRIGGER_DURATION',
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why is this name being changed?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Based on discussion with Courtney offline, it was mentioned that due to a bug the classification may have went to the wrong property bag Property<->Measures, hence changing name to avoid confusion and start afresh.

LANGUAGE_SERVER_TRIGGER_TIME = 'LANGUAGE_SERVER_TRIGGER_TIME',
LANGUAGE_SERVER_STARTUP = 'LANGUAGE_SERVER.STARTUP',
LANGUAGE_SERVER_READY = 'LANGUAGE_SERVER.READY',
LANGUAGE_SERVER_TELEMETRY = 'LANGUAGE_SERVER.EVENT',
Expand Down
17 changes: 14 additions & 3 deletions src/client/telemetry/index.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -723,6 +723,11 @@ export interface IEventNamePropertyMapping {
* If global interpreter is being used
*/
usingGlobalInterpreter?: boolean;
/**
* Carries `true` if it is the very first session of the user. We check whether persistent cache is empty
* to approximately guess if it's the first session.
*/
isFirstSession?: boolean;
};
/**
* Telemetry event sent when substituting Environment variables to calculate value of variables
Expand Down Expand Up @@ -1329,11 +1334,17 @@ export interface IEventNamePropertyMapping {
* Track how long it takes to trigger language server activation code, after Python extension starts activating.
*/
/* __GDPR__
"language_server_trigger_duration" : {
Copy link
Member

@cwebster-99 cwebster-99 Feb 20, 2024 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Spoke with Luciana and it seems like this should be language_server.trigger_duration to match the constant set in

vscode-python/src/client/telemetry/constants.ts

Line 67 in 75ed73e

LANGUAGE_SERVER_TRIGGER_DURATION = 'LANGUAGE_SERVER.TRIGGER_DURATION',

might not be the main problem but could be contributing. Looks like with your changes it is correct based on the name change.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, my new telemetry name matches it. You mentioned:

there may be a bug in the product code that provides classification, it has happened before where the classification went to the wrong property bag Property<->Measures

Based on which I changed the telemetry name. I think we should avoid using . so confusion like this does not happen in the future.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think the classification was addressed more so by adding "isMeasurement": true in the last PR. All that to say it looks like the changes you made in addition to the name change would address some of the other potential issues. We can try this!

"duration" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "karrtikr", "isMeasurement": true }
"language_server_trigger_time" : {
"duration" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "karrtikr" },
"triggerTime" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "karrtikr" }
}
*/
[EventName.LANGUAGE_SERVER_TRIGGER_DURATION]: unknown;
[EventName.LANGUAGE_SERVER_TRIGGER_TIME]: {
/**
* Time it took to trigger language server startup.
*/
triggerTime: number;
};
/**
* Telemetry event sent when starting Node.js server
*/
Expand Down