Skip to content
Merged
Show file tree
Hide file tree
Changes from 5 commits
Commits
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
1 change: 1 addition & 0 deletions packages/core/src/shared/logger/logger.ts
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@ export type LogTopic =
| 'stepfunctions'
| 'unknown'
| 'resourceCache'
| 'telemetry'

class ErrorLog {
constructor(
Expand Down
49 changes: 29 additions & 20 deletions packages/core/src/shared/telemetry/util.ts
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,7 @@ import {
} from '../vscode/env'
import { addTypeName } from '../utilities/typeConstructors'
import globals, { isWeb } from '../extensionGlobals'
import { mapMetadata } from './telemetryLogger'
import { mapMetadata, MetadataObj } from './telemetryLogger'
import { Result } from './telemetry.gen'
import { MetricDatum } from './clienttelemetry'
import { isValidationExemptMetric } from './exemptMetrics'
Expand Down Expand Up @@ -312,32 +312,41 @@ export async function getComputeEnvType(): Promise<EnvType> {

/**
* Validates that emitted telemetry metrics
* 1. contain a result property and
* 1. contain a result property
* 2. contain a reason propery if result = 'Failed'.
* 3. are not missing fields
*/
export function validateMetricEvent(event: MetricDatum, fatal: boolean) {
export function validateMetricEvent(event: MetricDatum, fatal: boolean, isExempt = isValidationExemptMetric) {
if (!isExempt(event.MetricName) && event.Metadata) {
const metadata = mapMetadata([])(event.Metadata)
validateMetadata(event.MetricName, metadata, fatal)
}
}

function validateMetadata(metricName: string, metadata: MetadataObj, fatal: boolean) {
const failedStr: Result = 'Failed'
const telemetryRunDocsStr =
const preferRunSuffix =
' Consider using `.run()` instead of `.emit()`, which will set these properties automatically. ' +
'See https://github.com/aws/aws-toolkit-vscode/blob/master/docs/telemetry.md#guidelines'

if (!isValidationExemptMetric(event.MetricName) && event.Metadata) {
const metadata = mapMetadata([])(event.Metadata)
let msg = 'telemetry: invalid Metric: '

if (metadata.result === undefined) {
msg += `"${event.MetricName}" emitted without the \`result\` property, which is always required.`
} else if (metadata.result === failedStr && metadata.reason === undefined) {
msg += `"${event.MetricName}" emitted with result=Failed but without the \`reason\` property.`
} else {
return // Validation passed.
}

msg += telemetryRunDocsStr
const msgPrefix = 'invalid Metric: '
const logger = getLogger('telemetry')
const logOrThrow = (msg: string, includeSuffix: boolean) => {
const fullMsg = msgPrefix + msg + (includeSuffix ? preferRunSuffix : '')
logger.warn(fullMsg)
if (fatal) {
throw new Error(msg)
throw new Error('telemetry: ' + fullMsg)
}
getLogger().warn(msg)
}

if (metadata.result === undefined) {
logOrThrow(`"${metricName}" emitted without the \`result\` property, which is always required.`, true)
} else if (metadata.result === failedStr && metadata.reason === undefined) {
logOrThrow(`"${metricName}" emitted with result=Failed but without the \`reason\` property.`, true)
}

// TODO: there are many instances in the toolkit where we emit metrics with missing fields. If those can be removed, we can configure this to throw in CI.
if (metadata.missingFields) {
logger.warn(msgPrefix + `"${metricName} emitted with missing fields: ${metadata.missingFields}`, false)
Copy link
Contributor

Choose a reason for hiding this comment

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

any concerns of this spamming the users logs too much?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

This is what I see after messing around in Q for a few minutes, so I am not too concerned.

2025-05-02 15:32:30.013 [warning] telemetry: invalid Metric: "languageServer_setup emitted with missing fields: id
2025-05-02 15:32:30.013 [warning] telemetry: invalid Metric: "languageServer_setup emitted with missing fields: id
2025-05-02 15:32:37.919 [warning] telemetry: invalid Metric: "languageServer_setup emitted with missing fields: id
2025-05-02 15:32:37.919 [warning] telemetry: invalid Metric: "languageServer_setup emitted with missing fields: id
2025-05-02 15:33:00.476 [warning] telemetry: invalid Metric: "amazonq_addMessage emitted with missing fields: cwsprChatTimeToFirstChunk
2025-05-02 15:34:09.534 [warning] telemetry: invalid Metric: "amazonq_addMessage emitted with missing fields: cwsprChatTimeToFirstChunk
2025-05-02 15:35:04.858 [warning] telemetry: invalid Metric: "amazonq_addMessage emitted with missing fields: cwsprChatTimeToFirstChunk
2025-05-02 15:36:13.968 [warning] telemetry: invalid Metric: "amazonq_addMessage emitted with missing fields: cwsprChatTimeToFirstChunk

I also checked Toolkit and wasn't able to find any of these. addMessage was fixed in aws/language-servers#1222. I can look into the languageServer_setup one as a follow-up.

Copy link
Contributor

Choose a reason for hiding this comment

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

we should probably do a logOnce thing for these warnings, since duplicates aren't useful

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Since this pattern seems somewhat common, I added a utility to execute functions once per unique argument. Then used that to implement the logOnce. (also refactored the processUtils to use it).

}
}

Expand Down
110 changes: 110 additions & 0 deletions packages/core/src/test/shared/telemetry/util.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -15,12 +15,15 @@ import {
SessionId,
telemetryClientIdEnvKey,
TelemetryConfig,
validateMetricEvent,
} from '../../../shared/telemetry/util'
import { extensionVersion } from '../../../shared/vscode/env'
import { FakeMemento } from '../../fakeExtensionContext'
import { GlobalState } from '../../../shared/globalState'
import { randomUUID } from 'crypto'
import { isUuid } from '../../../shared/crypto'
import { MetricDatum } from '../../../shared/telemetry/clienttelemetry'
import { assertLogsContain } from '../../globalSetup.test'

describe('TelemetryConfig', function () {
const settingKey = 'aws.telemetry'
Expand Down Expand Up @@ -281,3 +284,110 @@ describe('getUserAgent', function () {
assert.strictEqual(beforeClient, platformPair())
})
})

describe('validateMetricEvent', function () {
it('does not validate exempt metrics', function () {
const metricEvent: MetricDatum = {
MetricName: 'exempt_metric',
Value: 1,
Unit: 'None',
Metadata: [{ Key: 'result', Value: 'Succeeded' }],
} as MetricDatum

validateMetricEvent(metricEvent, true, (_) => true)
assert.throws(() => assertLogsContain('invalid Metric', false, 'warn'))
})

it('passes validation for metrics with proper result property', function () {
const metricEvent: MetricDatum = {
MetricName: 'valid_metric',
Value: 1,
Unit: 'None',
Metadata: [{ Key: 'result', Value: 'Succeeded' }],
} as MetricDatum

validateMetricEvent(metricEvent, true, (_) => false)
assert.throws(() => assertLogsContain('invalid Metric', false, 'warn'))
})

it('passes validation for metrics with Failed result and reason property', function () {
const metricEvent: MetricDatum = {
MetricName: 'valid_failed_metric',
Value: 1,
Unit: 'None',
Metadata: [
{ Key: 'result', Value: 'Failed' },
{ Key: 'reason', Value: 'Something went wrong' },
],
} as MetricDatum

validateMetricEvent(metricEvent, true, (_) => false)
})

it('fails validation for metrics missing result property when fatal=true', function () {
const metricEvent: MetricDatum = {
MetricName: 'invalid_metric_no_result',
Value: 1,
Unit: 'None',
Metadata: [{ Key: 'someOtherProperty', Value: 'value' }],
} as MetricDatum

assert.throws(
() => validateMetricEvent(metricEvent, true, (_) => false),
/emitted without the `result` property/
)
})

it('logs warning for metrics missing result property when fatal=false', function () {
const metricEvent: MetricDatum = {
MetricName: 'invalid_metric_no_result',
Value: 1,
Unit: 'None',
Metadata: [{ Key: 'someOtherProperty', Value: 'value' }],
} as MetricDatum

validateMetricEvent(metricEvent, false, (_) => false)
assertLogsContain('invalid Metric', false, 'warn')
})

it('fails validation for metrics with Failed result but missing reason property when fatal=true', function () {
const metricEvent: MetricDatum = {
MetricName: 'invalid_metric_failed_no_reason',
Value: 1,
Unit: 'None',
Metadata: [{ Key: 'result', Value: 'Failed' }],
} as MetricDatum

assert.throws(
() => validateMetricEvent(metricEvent, true),
/emitted with result=Failed but without the `reason` property/
)
})

it('logs warning for metrics with Failed result but missing reason property when fatal=false', function () {
const metricEvent: MetricDatum = {
MetricName: 'invalid_metric_failed_no_reason',
Value: 1,
Unit: 'None',
Metadata: [{ Key: 'result', Value: 'Failed' }],
} as MetricDatum

validateMetricEvent(metricEvent, false)
assertLogsContain('invalid Metric', false, 'warn')
})

it('does not fail validation for metrics with missing fields with fatal=true', function () {
const metricEvent: MetricDatum = {
MetricName: 'invalid_metric_missing_fields',
Value: 1,
Unit: 'None',
Metadata: [
{ Key: 'result', Value: 'Succeeded' },
{ Key: 'missingFields', Value: 'field1,field2' },
],
} as MetricDatum

validateMetricEvent(metricEvent, false)
assertLogsContain('invalid Metric', false, 'warn')
})
})
Loading