Fix telemetry cache (#926)

Author: hunterwerlla

src/shared/telemetry/defaultTelemetryClient.ts

@@ -27,6 +27,12 @@ export class DefaultTelemetryClient implements TelemetryClient {
      */
     public async postMetrics(batch: TelemetryEvent[]): Promise<TelemetryEvent[] | undefined> {
         try {
+            const metricData = toMetricData(batch)
+            // If our batching logic rejected all of the telemetry, don't try to post
+            if (metricData.length === 0) {
+                return undefined
+            }
+
             await this.client
                 .postMetrics({
                     AWSProduct: DefaultTelemetryClient.PRODUCT_NAME,
@@ -36,10 +42,12 @@ export class DefaultTelemetryClient implements TelemetryClient {
                     OSVersion: os.release(),
                     ParentProduct: vscode.env.appName,
                     ParentProductVersion: vscode.version,
-                    MetricData: toMetricData(batch)
+                    MetricData: metricData
                 })
                 .promise()
             console.info(`Successfully sent a telemetry batch of ${batch.length}`)
+
+            return undefined
         } catch (err) {
             console.error(`Batch error: ${err}`)
 

src/shared/telemetry/defaultTelemetryService.ts

@@ -9,6 +9,7 @@ import * as path from 'path'
 import uuidv4 = require('uuid/v4')
 import { ExtensionContext } from 'vscode'
 import { AwsContext } from '../awsContext'
+import { getLogger } from '../logger'
 import { DefaultTelemetryClient } from './defaultTelemetryClient'
 import { DefaultTelemetryPublisher } from './defaultTelemetryPublisher'
 import { recordSessionEnd, recordSessionStart } from './telemetry'
@@ -48,8 +49,8 @@ export class DefaultTelemetryService implements TelemetryService {
         }
 
         this.startTime = new Date()
-        this._eventQueue = DefaultTelemetryService.readEventsFromCache(this.persistFilePath)
 
+        this._eventQueue = []
         this._flushPeriod = DefaultTelemetryService.DEFAULT_FLUSH_PERIOD_MILLIS
 
         if (publisher !== undefined) {
@@ -62,6 +63,7 @@ export class DefaultTelemetryService implements TelemetryService {
     }
 
     public async start(): Promise<void> {
+        this._eventQueue.push(...DefaultTelemetryService.readEventsFromCache(this.persistFilePath))
         recordSessionStart()
         await this.startTimer()
     }
@@ -244,14 +246,72 @@ export class DefaultTelemetryService implements TelemetryService {
 
     private static readEventsFromCache(cachePath: string): TelemetryEvent[] {
         try {
-            const events = JSON.parse(fs.readFileSync(cachePath, 'utf-8')) as TelemetryEvent[]
+            const input = JSON.parse(fs.readFileSync(cachePath, 'utf-8'))
+            const events = filterTelemetryCacheEvents(input)
             events.forEach((element: TelemetryEvent) => {
+                // This is coercing the createTime into a Date type: it's read in as a string
                 element.createTime = new Date(element.createTime)
             })
 
             return events
-        } catch {
+        } catch (error) {
+            // tslint:disable-next-line: no-unsafe-any
+            getLogger().error(error)
+
             return []
         }
     }
 }
+
+export function filterTelemetryCacheEvents(input: any): TelemetryEvent[] {
+    if (!Array.isArray(input)) {
+        getLogger().error(`Input into filterTelemetryCacheEvents:\n${input}\nis not an array!`)
+
+        return []
+    }
+    const arr = input as any[]
+
+    return arr
+        .filter((item: any) => {
+            // Make sure the item is an object
+            if (item !== Object(item)) {
+                getLogger().error(`Item in telemetry cache:\n${item}\nis not an object! skipping!`)
+
+                return false
+            }
+
+            return true
+        })
+        .filter((item: Object) => {
+            // Only accept objects that have createTime and data because that's what's required by TelemetryEvent
+            if (!item.hasOwnProperty('createTime') || !item.hasOwnProperty('data')) {
+                getLogger().warn(`Item in telemetry cache: ${item}\n does not have 'data' or 'createTime'! skipping!`)
+
+                return false
+            }
+
+            return true
+        })
+        .filter((item: TelemetryEvent) => {
+            // skip it if data is not an array or empty
+            if (!Array.isArray(item.data) || item.data.length === 0) {
+                getLogger().warn(`Item in telemetry cache: ${item}\n has invalid data field: ${item.data}! skipping!`)
+
+                return false
+            }
+
+            // Only accept objects that have value and metricname which are the base things required for telemetry
+            return item.data.every(data => {
+                // Make sure data is actually an object then check that it has the required properties
+                if (data !== Object(data) || !data.hasOwnProperty('Value') || !data.hasOwnProperty('MetricName')) {
+                    getLogger().warn(
+                        `Item in telemetry cache: ${item}\n has invalid data in the field 'data': ${data}! skipping!`
+                    )
+
+                    return false
+                }
+
+                return true
+            })
+        }) as TelemetryEvent[]
+}

src/shared/telemetry/telemetryEvent.ts

@@ -18,16 +18,26 @@ export function toMetricData(array: TelemetryEvent[]): MetricDatum[] {
             .filter(item => {
                 return item.data !== undefined
             })
-            .map(metricEvent =>
-                metricEvent.data.map(datum => {
-                    return {
-                        MetricName: datum.MetricName?.replace(NAME_ILLEGAL_CHARS_REGEX, ''),
-                        EpochTimestamp: metricEvent.createTime.getTime(),
-                        Unit: datum.Unit ?? 'None',
-                        Value: datum.Value,
-                        Metadata: datum.Metadata
-                    }
-                })
+            .map((metricEvent: TelemetryEvent) =>
+                metricEvent.data
+                    .filter(datum => {
+                        const name = datum.MetricName?.replace(NAME_ILLEGAL_CHARS_REGEX, '')
+                        // Filter out bad data
+                        if (name === undefined || name === '' || datum.Value === undefined) {
+                            return false
+                        }
+
+                        return true
+                    })
+                    .map(datum => {
+                        return {
+                            MetricName: datum.MetricName?.replace(NAME_ILLEGAL_CHARS_REGEX, ''),
+                            EpochTimestamp: metricEvent.createTime.getTime(),
+                            Unit: datum.Unit ?? 'None',
+                            Value: datum.Value,
+                            Metadata: datum.Metadata
+                        }
+                    })
             )
     )
 }

src/test/shared/telemetry/defaultTelemetryService.test.ts

@@ -4,6 +4,7 @@
  */
 
 import * as assert from 'assert'
+import * as del from 'del'
 // tslint:disable-next-line:no-implicit-dependencies
 import * as lolex from 'lolex'
 import * as sinon from 'sinon'
@@ -53,6 +54,8 @@ beforeEach(() => {
 })
 
 afterEach(() => {
+    // Remove the persist file as it is saved
+    del.sync([ext.telemetry.persistFilePath], { force: true })
     ext.telemetry = originalTelemetryClient
 })
 

src/test/shared/telemetry/telemetryCache.test.ts

@@ -0,0 +1,42 @@
+/*!
+ * Copyright 2020 Amazon.com, Inc. or its affiliates. All Rights Reserved.
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+import * as assert from 'assert'
+import { filterTelemetryCacheEvents } from '../../../shared/telemetry/defaultTelemetryService'
+
+describe('Telemetry cache', () => {
+    it('Rejects bad data', () => {
+        const input = "THis isn't even valid json"
+
+        const output = filterTelemetryCacheEvents(input)
+        assert.strictEqual(output.length, 0)
+    })
+
+    it('Filters out old data', () => {
+        const input = JSON.parse(
+            '[{"namespace":"session","createTime":"2020-01-07T22:24:13.356Z","data":[{"name":"end","value":4226661,"unit":"Milliseconds","metadata":{}}]}]'
+        )
+
+        const output = filterTelemetryCacheEvents(input)
+        assert.strictEqual(output.length, 0)
+    })
+
+    it('Extracts good data when there is bad data present', () => {
+        const input = JSON.parse(
+            '["this is a string", {"namespace":"session","createTime":"2020-01-07T22:24:13.356Z","data":[{"name":"end","value":4226661,"unit":"Milliseconds","metadata":{}}]},{"createTime":"2020-02-07T16:54:58.293Z","data":[{"MetricName":"session_end","Value":18709,"Unit":"None","Metadata":[{"Key":"awsAccount","Value":"n/a"}]}]}]'
+        )
+
+        const output = filterTelemetryCacheEvents(input)
+        assert.strictEqual(output.length, 1)
+    })
+
+    it('Happy path', () => {
+        const input = JSON.parse(
+            '[{"createTime":"2020-02-07T16:54:58.293Z","data":[{"MetricName":"session_end","Value":18709,"Unit":"None","Metadata":[{"Key":"awsAccount","Value":"n/a"}]}]}]'
+        )
+        const output = filterTelemetryCacheEvents(input)
+        assert.strictEqual(output.length, 1)
+    })
+})

src/test/shared/telemetry/telemetryEvent.test.ts

@@ -59,6 +59,55 @@ describe('TelemetryEventArray', () => {
             assert.deepStrictEqual(data[0].Metadata, undefined)
         })
 
+        it('Rejects entries that have null Value', () => {
+            const eventArray: TelemetryEvent[] = []
+            const metricEvent = {
+                createTime: new Date(),
+                data: [
+                    {
+                        MetricName: 'namespace_event2',
+                        Value: undefined,
+                        Unit: 'Percent',
+                        Metadata: [
+                            { Key: 'key', Value: 'value' },
+                            { Key: 'key2', Value: 'value2' }
+                        ]
+                    },
+                    {
+                        MetricName: 'namespace_event3',
+                        Unit: 'Percent',
+                        Value: 0.333,
+                        Metadata: [{ Key: 'key3', Value: 'value3' }]
+                    }
+                ]
+            }
+            eventArray.push(metricEvent)
+            const data = toMetricData(eventArray)
+            assert.strictEqual(data.length, 1)
+        })
+
+        it('Rejects entries that have null MetricName', () => {
+            const eventArray: TelemetryEvent[] = []
+            const metricEvent = {
+                createTime: new Date(),
+                data: [
+                    {
+                        MetricName: undefined,
+                        Value: 1
+                    },
+                    {
+                        MetricName: 'namespace_event3',
+                        Unit: 'Percent',
+                        Value: 0.333,
+                        Metadata: [{ Key: 'key3', Value: 'value3' }]
+                    }
+                ]
+            }
+            eventArray.push(metricEvent)
+            const data = toMetricData(eventArray)
+            assert.strictEqual(data.length, 1)
+        })
+
         it('maps TelemetryEvent with data to a multiple MetricDatum', () => {
             const eventArray: TelemetryEvent[] = []
             const metricEvent = {