add telemetry appender that writes to log (#53603)

* add log-telemetry-appender and wire it up in the shell

* enable log-only-telemetry in scripts/code.[sh|bat]

* Reduce noise, separate log file for telemetry

* Print telemetry events from shared process to corresponding log channel

* Telemetry events for cli go to the log file for cli

* Merge cli telemetry with all data with cli log

* Use LogAppender when running from source

* Skip check on isBuilt as the same is done in the shared process

* Telemetry events from main process go to corresponding log file

* Telemetry events from issue reporter go to corresponding log file

* Cleanup to reduce diff amount as I have OCD

* More cleanup

* Open telemetry log file via the Open Log File command

* Use regex to strip out common data

* Tests
This commit is contained in:
Johannes Rieken 2018-07-11 21:21:40 +02:00 committed by Ramya Rao
parent ab4338f19d
commit 19f25e4801
10 changed files with 132 additions and 35 deletions

View file

@ -4,6 +4,7 @@
"applicationName": "code-oss",
"dataFolderName": ".vscode-oss",
"win32MutexName": "vscodeoss",
"enableTelemetry": true,
"licenseName": "MIT",
"licenseUrl": "https://github.com/Microsoft/vscode/blob/master/LICENSE.txt",
"win32DirName": "Microsoft Code OSS",
@ -22,4 +23,4 @@
"ms-vscode.node-debug",
"ms-vscode.node-debug2"
]
}
}

View file

@ -23,7 +23,7 @@ import { getDelayedChannel } from 'vs/base/parts/ipc/common/ipc';
import { connect as connectNet } from 'vs/base/parts/ipc/node/ipc.net';
import { ServiceCollection } from 'vs/platform/instantiation/common/serviceCollection';
import { IWindowConfiguration, IWindowsService } from 'vs/platform/windows/common/windows';
import { NullTelemetryService } from 'vs/platform/telemetry/common/telemetryUtils';
import { NullTelemetryService, combinedAppender, LogAppender } from 'vs/platform/telemetry/common/telemetryUtils';
import { IEnvironmentService } from 'vs/platform/environment/common/environment';
import { ITelemetryServiceConfig, TelemetryService } from 'vs/platform/telemetry/common/telemetryService';
import { ITelemetryAppenderChannel, TelemetryAppenderClient } from 'vs/platform/telemetry/common/telemetryIpc';
@ -287,9 +287,9 @@ export class IssueReporter extends Disposable {
.then(() => connectNet(this.environmentService.sharedIPCHandle, `window:${configuration.windowId}`));
const instantiationService = new InstantiationService(serviceCollection, true);
if (this.environmentService.isBuilt && !this.environmentService.isExtensionDevelopment && !this.environmentService.args['disable-telemetry'] && !!product.enableTelemetry) {
if (!this.environmentService.isExtensionDevelopment && !this.environmentService.args['disable-telemetry'] && !!product.enableTelemetry) {
const channel = getDelayedChannel<ITelemetryAppenderChannel>(sharedProcess.then(c => c.getChannel('telemetryAppender')));
const appender = new TelemetryAppenderClient(channel);
const appender = combinedAppender(new TelemetryAppenderClient(channel), new LogAppender(logService));
const commonProperties = resolveCommonProperties(product.commit, pkg.version, configuration.machineId, this.environmentService.installSourcePath);
const piiPaths = [this.environmentService.appRoot, this.environmentService.extensionsPath];
const config: ITelemetryServiceConfig = { appender, commonProperties, piiPaths };

View file

@ -25,7 +25,7 @@ import { ConfigurationService } from 'vs/platform/configuration/node/configurati
import { IRequestService } from 'vs/platform/request/node/request';
import { RequestService } from 'vs/platform/request/electron-browser/requestService';
import { ITelemetryService } from 'vs/platform/telemetry/common/telemetry';
import { combinedAppender, NullTelemetryService } from 'vs/platform/telemetry/common/telemetryUtils';
import { combinedAppender, NullTelemetryService, ITelemetryAppender, NullAppender, LogAppender } from 'vs/platform/telemetry/common/telemetryUtils';
import { resolveCommonProperties } from 'vs/platform/telemetry/node/commonProperties';
import { TelemetryAppenderChannel } from 'vs/platform/telemetry/common/telemetryIpc';
import { TelemetryService, ITelemetryServiceConfig } from 'vs/platform/telemetry/common/telemetryService';
@ -91,26 +91,21 @@ function main(server: Server, initData: ISharedProcessInitData, configuration: I
const instantiationService = new InstantiationService(services);
instantiationService.invokeFunction(accessor => {
const appenders: AppInsightsAppender[] = [];
if (product.aiConfig && product.aiConfig.asimovKey) {
appenders.push(new AppInsightsAppender(eventPrefix, null, product.aiConfig.asimovKey));
}
// It is important to dispose the AI adapter properly because
// only then they flush remaining data.
disposables.push(...appenders);
const appender = combinedAppender(...appenders);
server.registerChannel('telemetryAppender', new TelemetryAppenderChannel(appender));
const services = new ServiceCollection();
const environmentService = accessor.get(IEnvironmentService);
const { appRoot, extensionsPath, extensionDevelopmentPath, isBuilt, installSourcePath } = environmentService;
const telemetryLogService = new FollowerLogService(logLevelClient, createSpdLogService('telemetry', initData.logLevel, environmentService.logsPath));
if (isBuilt && !extensionDevelopmentPath && !environmentService.args['disable-telemetry'] && product.enableTelemetry) {
let appInsightsAppender: ITelemetryAppender = NullAppender;
if (product.aiConfig && product.aiConfig.asimovKey && isBuilt) {
appInsightsAppender = new AppInsightsAppender(eventPrefix, null, product.aiConfig.asimovKey, telemetryLogService);
disposables.push(appInsightsAppender); // Ensure the AI appender is disposed so that it flushes remaining data
}
server.registerChannel('telemetryAppender', new TelemetryAppenderChannel(appInsightsAppender));
if (!extensionDevelopmentPath && !environmentService.args['disable-telemetry'] && product.enableTelemetry) {
const config: ITelemetryServiceConfig = {
appender,
appender: combinedAppender(appInsightsAppender, new LogAppender(logService)),
commonProperties: resolveCommonProperties(product.commit, pkg.version, configuration.machineId, installSourcePath),
piiPaths: [appRoot, extensionsPath]
};

View file

@ -30,7 +30,7 @@ import { IConfigurationService } from 'vs/platform/configuration/common/configur
import { IURLService } from 'vs/platform/url/common/url';
import { URLHandlerChannelClient, URLServiceChannel } from 'vs/platform/url/common/urlIpc';
import { ITelemetryService } from 'vs/platform/telemetry/common/telemetry';
import { NullTelemetryService } from 'vs/platform/telemetry/common/telemetryUtils';
import { NullTelemetryService, combinedAppender, LogAppender } from 'vs/platform/telemetry/common/telemetryUtils';
import { ITelemetryAppenderChannel, TelemetryAppenderClient } from 'vs/platform/telemetry/common/telemetryIpc';
import { TelemetryService, ITelemetryServiceConfig } from 'vs/platform/telemetry/common/telemetryService';
import { resolveCommonProperties } from 'vs/platform/telemetry/node/commonProperties';
@ -362,9 +362,9 @@ export class CodeApplication {
services.set(IMenubarService, new SyncDescriptor(MenubarService));
// Telemtry
if (this.environmentService.isBuilt && !this.environmentService.isExtensionDevelopment && !this.environmentService.args['disable-telemetry'] && !!product.enableTelemetry) {
if (!this.environmentService.isExtensionDevelopment && !this.environmentService.args['disable-telemetry'] && !!product.enableTelemetry) {
const channel = getDelayedChannel<ITelemetryAppenderChannel>(this.sharedProcessClient.then(c => c.getChannel('telemetryAppender')));
const appender = new TelemetryAppenderClient(channel);
const appender = combinedAppender(new TelemetryAppenderClient(channel), new LogAppender(this.logService));
const commonProperties = resolveCommonProperties(product.commit, pkg.version, machineId, this.environmentService.installSourcePath);
const piiPaths = [this.environmentService.appRoot, this.environmentService.extensionsPath];
const config: ITelemetryServiceConfig = { appender, commonProperties, piiPaths };

View file

@ -245,7 +245,7 @@ export function main(argv: ParsedArgs): TPromise<void> {
if (isBuilt && !extensionDevelopmentPath && !envService.args['disable-telemetry'] && product.enableTelemetry) {
if (product.aiConfig && product.aiConfig.asimovKey) {
appenders.push(new AppInsightsAppender(eventPrefix, null, product.aiConfig.asimovKey));
appenders.push(new AppInsightsAppender(eventPrefix, null, product.aiConfig.asimovKey, logService));
}
const config: ITelemetryServiceConfig = {

View file

@ -12,6 +12,7 @@ import URI from 'vs/base/common/uri';
import { IConfigurationService, ConfigurationTarget } from 'vs/platform/configuration/common/configuration';
import { IKeybindingService, KeybindingSource } from 'vs/platform/keybinding/common/keybinding';
import { ITelemetryService, ITelemetryInfo, ITelemetryData } from 'vs/platform/telemetry/common/telemetry';
import { ILogService } from 'vs/platform/log/common/log';
export const NullTelemetryService = new class implements ITelemetryService {
_serviceBrand: undefined;
@ -42,6 +43,27 @@ export function combinedAppender(...appenders: ITelemetryAppender[]): ITelemetry
export const NullAppender: ITelemetryAppender = { log: () => null, dispose: () => TPromise.as(null) };
export class LogAppender implements ITelemetryAppender {
private commonPropertiesRegex = /^sessionID$|^version$|^timestamp$|^common\./;
constructor(@ILogService private readonly _logService: ILogService) { }
dispose(): TPromise<any> {
return TPromise.as(undefined);
}
log(eventName: string, data: any): void {
const strippedData = {};
Object.keys(data).forEach(key => {
if (!this.commonPropertiesRegex.test(key)) {
strippedData[key] = data[key];
}
});
this._logService.trace(`telemetry/${eventName}`, strippedData);
}
}
/* __GDPR__FRAGMENT__
"URIDescriptor" : {
"mimeType" : { "classification": "SystemMetaData", "purpose": "FeatureInsight" },

View file

@ -9,6 +9,7 @@ import { isObject } from 'vs/base/common/types';
import { safeStringify, mixin } from 'vs/base/common/objects';
import { TPromise } from 'vs/base/common/winjs.base';
import { ITelemetryAppender } from 'vs/platform/telemetry/common/telemetryUtils';
import { ILogService } from 'vs/platform/log/common/log';
let _initialized = false;
@ -53,7 +54,8 @@ export class AppInsightsAppender implements ITelemetryAppender {
constructor(
private _eventPrefix: string,
private _defaultData: { [key: string]: any },
aiKeyOrClientFactory: string | (() => typeof appInsights.client) // allow factory function for testing
aiKeyOrClientFactory: string | (() => typeof appInsights.client), // allow factory function for testing
@ILogService private _logService?: ILogService
) {
if (!this._defaultData) {
this._defaultData = Object.create(null);
@ -133,8 +135,12 @@ export class AppInsightsAppender implements ITelemetryAppender {
return;
}
data = mixin(data, this._defaultData);
let { properties, measurements } = AppInsightsAppender._getData(data);
this._aiClient.trackEvent(this._eventPrefix + '/' + eventName, properties, measurements);
data = AppInsightsAppender._getData(data);
if (this._logService) {
this._logService.trace(`telemetry/${eventName}`, data);
}
this._aiClient.trackEvent(this._eventPrefix + '/' + eventName, data.properties, data.measurements);
}
dispose(): TPromise<any> {

View file

@ -6,6 +6,7 @@
import * as assert from 'assert';
import { AppInsightsAppender } from 'vs/platform/telemetry/node/appInsightsAppender';
import { ILogService, AbstractLogService, LogLevel, DEFAULT_LOG_LEVEL } from 'vs/platform/log/common/log';
interface IAppInsightsEvent {
eventName: string;
@ -39,11 +40,61 @@ class AppInsightsMock {
}
}
class TestableLogService extends AbstractLogService implements ILogService {
_serviceBrand: any;
public logs: string[] = [];
constructor(logLevel: LogLevel = DEFAULT_LOG_LEVEL) {
super();
this.setLevel(logLevel);
}
trace(message: string, ...args: any[]): void {
if (this.getLevel() <= LogLevel.Trace) {
this.logs.push(message + JSON.stringify(args));
}
}
debug(message: string, ...args: any[]): void {
if (this.getLevel() <= LogLevel.Debug) {
this.logs.push(message);
}
}
info(message: string, ...args: any[]): void {
if (this.getLevel() <= LogLevel.Info) {
this.logs.push(message);
}
}
warn(message: string | Error, ...args: any[]): void {
if (this.getLevel() <= LogLevel.Warning) {
this.logs.push(message.toString());
}
}
error(message: string, ...args: any[]): void {
if (this.getLevel() <= LogLevel.Error) {
this.logs.push(message);
}
}
critical(message: string, ...args: any[]): void {
if (this.getLevel() <= LogLevel.Critical) {
this.logs.push(message);
}
}
dispose(): void { }
}
suite('AIAdapter', () => {
var appInsightsMock: AppInsightsMock;
var adapter: AppInsightsAppender;
var prefix = 'prefix';
setup(() => {
appInsightsMock = new AppInsightsMock();
adapter = new AppInsightsAppender(prefix, undefined, () => appInsightsMock);
@ -141,4 +192,27 @@ suite('AIAdapter', () => {
assert.equal(appInsightsMock.events[0].properties['nestedObj.nestedObj2.nestedObj3'], JSON.stringify({ 'testProperty': 'test' }));
assert.equal(appInsightsMock.events[0].measurements['nestedObj.testMeasurement'], 1);
});
test('Do not Log Telemetry if log level is not trace', () => {
const logService = new TestableLogService(LogLevel.Info);
adapter = new AppInsightsAppender(prefix, { 'common.platform': 'Windows' }, () => appInsightsMock, logService);
adapter.log('testEvent', { hello: 'world', isTrue: true, numberBetween1And3: 2 });
assert.equal(logService.logs.length, 0);
});
test('Log Telemetry if log level is trace', () => {
const logService = new TestableLogService(LogLevel.Trace);
adapter = new AppInsightsAppender(prefix, { 'common.platform': 'Windows' }, () => appInsightsMock, logService);
adapter.log('testEvent', { hello: 'world', isTrue: true, numberBetween1And3: 2 });
assert.equal(logService.logs.length, 1);
assert.equal(logService.logs[0], 'telemetry/testEvent' + JSON.stringify([{
properties: {
hello: 'world',
'common.platform': 'Windows'
},
measurements: {
isTrue: 1, numberBetween1And3: 2
}
}]));
});
});

View file

@ -18,7 +18,7 @@ import { SyncDescriptor } from 'vs/platform/instantiation/common/descriptors';
import pkg from 'vs/platform/node/package';
import { Workbench, IWorkbenchStartedInfo } from 'vs/workbench/electron-browser/workbench';
import { ITelemetryService } from 'vs/platform/telemetry/common/telemetry';
import { NullTelemetryService, configurationTelemetry } from 'vs/platform/telemetry/common/telemetryUtils';
import { NullTelemetryService, configurationTelemetry, combinedAppender, LogAppender } from 'vs/platform/telemetry/common/telemetryUtils';
import { ITelemetryAppenderChannel, TelemetryAppenderClient } from 'vs/platform/telemetry/common/telemetryIpc';
import { TelemetryService, ITelemetryServiceConfig } from 'vs/platform/telemetry/common/telemetryService';
import ErrorTelemetry from 'vs/platform/telemetry/browser/errorTelemetry';
@ -350,14 +350,12 @@ export class WorkbenchShell extends Disposable {
serviceCollection.set(IHashService, new SyncDescriptor(HashService));
// Telemetry
if (this.environmentService.isBuilt && !this.environmentService.isExtensionDevelopment && !this.environmentService.args['disable-telemetry'] && !!product.enableTelemetry) {
const channel = getDelayedChannel<ITelemetryAppenderChannel>(sharedProcess.then(c => c.getChannel('telemetryAppender')));
const commit = product.commit;
const version = pkg.version;
if (!this.environmentService.isExtensionDevelopment && !this.environmentService.args['disable-telemetry'] && !!product.enableTelemetry) {
const channel = getDelayedChannel<ITelemetryAppenderChannel>(sharedProcess.then(c => c.getChannel('telemetryAppender')));
const config: ITelemetryServiceConfig = {
appender: new TelemetryAppenderClient(channel),
commonProperties: resolveWorkbenchCommonProperties(this.storageService, commit, version, this.configuration.machineId, this.environmentService.installSourcePath),
appender: combinedAppender(new TelemetryAppenderClient(channel), new LogAppender(this.logService)),
commonProperties: resolveWorkbenchCommonProperties(this.storageService, product.commit, pkg.version, this.configuration.machineId, this.environmentService.installSourcePath),
piiPaths: [this.environmentService.appRoot, this.environmentService.extensionsPath]
};

View file

@ -85,7 +85,8 @@ export class OpenLogFileAction extends Action {
{ id: URI.file(paths.join(this.environmentService.logsPath, `renderer${this.windowService.getCurrentWindowId()}.log`)).fsPath, label: this.contextService.getWorkspace().name ? nls.localize('rendererProcess', "Window ({0})", this.contextService.getWorkspace().name) : nls.localize('emptyWindow', "Window") },
{ id: URI.file(paths.join(this.environmentService.logsPath, `exthost${this.windowService.getCurrentWindowId()}.log`)).fsPath, label: nls.localize('extensionHost', "Extension Host") },
{ id: URI.file(paths.join(this.environmentService.logsPath, `sharedprocess.log`)).fsPath, label: nls.localize('sharedProcess', "Shared") },
{ id: URI.file(paths.join(this.environmentService.logsPath, `main.log`)).fsPath, label: nls.localize('mainProcess', "Main") }
{ id: URI.file(paths.join(this.environmentService.logsPath, `main.log`)).fsPath, label: nls.localize('mainProcess', "Main") },
{ id: URI.file(paths.join(this.environmentService.logsPath, `telemetry.log`)).fsPath, label: nls.localize('telemetry', "Telemetry") }
];
return this.quickOpenService.pick(entries, { placeHolder: nls.localize('selectProcess', "Select Log for Process") })