Skip to content

Commit 135c3e5

Browse files
refactor(telemetry): add functionality to @withTelemetryContext (#5816)
See each commit for the specific change. But this has multiple improvements to the `@withTelemetryContext` decorator. The main change to note: - Adding the `@withTelemetryContext` decorator to a method can wrap thrown errors with context about that function. This helps us to build some sort of stack trace in the `reasonDesc` of our telemetry when errors are thrown. - [This is the documentation updated to get a better idea of what this is](https://github.com/aws/aws-toolkit-vscode/blob/b3f2ad9c65b47cd61ca72652171e932ef2480d8c/docs/telemetry.md#adding-a-stack-trace-to-your-metric) - The decorator allows for minimal diffs to the code. It is replacing [this previous code](https://github.com/aws/aws-toolkit-vscode/blob/2a72e6df814e3cbabce1cfe2476f1ca98ea8de2b/packages/core/src/shared/crashMonitoring.ts#L651) which would cause a diff in the column indentation since all the method code needed to be in a callback --- <!--- REMINDER: Ensure that your PR meets the guidelines in CONTRIBUTING.md --> License: I confirm that my contribution is made under the terms of the Apache 2.0 license. --------- Signed-off-by: nkomonen-amazon <[email protected]>
1 parent bd23e71 commit 135c3e5

File tree

4 files changed

+201
-53
lines changed

4 files changed

+201
-53
lines changed

docs/telemetry.md

Lines changed: 48 additions & 34 deletions
Original file line numberDiff line numberDiff line change
@@ -142,20 +142,23 @@ Finally, if `setupStep2()` was the thing that failed we would see a metric like:
142142

143143
## Adding a "Stack Trace" to your metric
144144

145-
### Problem
145+
When errors are thrown we do not attach the stack trace in telemetry. We only know about the error itself, but
146+
not the path it took to get there. We sometimes need this stack trace to debug, and only have telemetry to get insight on what happened since we do not have access to logs.
147+
148+
### Scenario
146149

147150
Common example: _"I have a function, `thisFailsSometimes()` that is called in multiple places. The function sometimes fails, I know from telemetry, but I do not know if it is failing when it is a specific caller. If I knew the call stack/trace that it took to call my function that would help me debug."_
148151

149152
```typescript
150-
function outerA() {
153+
function runsSuccessfully() {
151154
thisFailsSometimes(1) // this succeeds
152155
}
153156

154-
function outerB() {
157+
function thisThrows() {
155158
thisFailsSometimes(0) // this fails
156159
}
157160

158-
function thisFailsSometimes(num: number) {
161+
function failsDependingOnInput(num: number) {
159162
return telemetry.my_Metric.run(() => {
160163
if (number === 0) {
161164
throw Error('Cannot be 0')
@@ -167,31 +170,61 @@ function thisFailsSometimes(num: number) {
167170

168171
### Solution
169172

170-
Add a value to `function` in the options of a `run()`. This will result in a stack of functions identifiers that were previously called
171-
before `thisFailsSometimes()` was run. You can then retrieve the stack in the `run()` of your final metric using `getFunctionStack()`.
173+
On class methods, use the `@withTelemetryContext()` decorator to add context to the execution. Depending on the args set, it provides features like emitting the result, or adding it's context to errors.
174+
175+
> NOTE: Decorators are currently only supported for methods and not functions
176+
177+
```typescript
178+
class MyClass {
179+
@withTelemetryContext({ name: 'runsSuccessfully', class: 'MyClass' })
180+
public runsSuccessfully() {
181+
failsDependingOnInput(1)
182+
}
183+
184+
@withTelemetryContext({ name: 'thisThrows', class: 'MyClass', errorCtx: true })
185+
public thisThrows() {
186+
failsDependingOnInput(0)
187+
}
188+
189+
@withTelemetryContext({ name: 'failsDependingOnInput' class: 'MyClass', emit: true, errorCtx: true})
190+
private failsDependingOnInput(num: number) {
191+
if (number === 0) {
192+
throw Error('Cannot be 0')
193+
}
194+
...
195+
}
196+
}
197+
198+
// Results in a metric: { source: 'MyClass#thisThrows,failsDependingOnInput', result: 'Failed' }
199+
// Results in an error that has context about the methods that lead up to it.
200+
new MyClass().thisThrows()
201+
```
202+
203+
Separately if you must use a function, add a value to `function` in the options of a `run()`. This will result in a stack of functions identifiers that were previously called
204+
before `failsDependingOnInput()` was run. You can then retrieve the stack in the `run()` of your final metric using `getFunctionStack()`.
172205

173206
```typescript
174-
function outerA() {
175-
telemetry.my_Metric.run(() => thisFailsSometimes(1), { functionId: { name: 'outerA' }})
207+
function runsSuccessfully() {
208+
telemetry.my_Metric.run(() => failsDependingOnInput(1), { functionId: { name: 'runsSuccessfully' }})
176209
}
177210

178-
function outerB() {
179-
telemetry.my_Metric.run(() => thisFailsSometimes(0), { functionId: { source: 'outerB' }})
211+
function thisThrows() {
212+
telemetry.my_Metric.run(() => failsDependingOnInput(0), { functionId: { source: 'thisThrows' }})
180213
}
181214

182-
function thisFailsSometimes(num: number) {
215+
function failsDependingOnInput(num: number) {
183216
return telemetry.my_Metric.run(() => {
184217
telemetry.record({ theCallStack: asStringifiedStack(telemetry.getFunctionStack())})
185218
if (number === 0) {
186219
throw Error('Cannot be 0')
187220
}
188221
...
189-
}, { functionId: { name: 'thisFailsSometimes' }})
222+
}, { functionId: { name: 'failsDependingOnInput' }})
190223
}
191224

192-
// Results in a metric: { theCallStack: 'outerB:thisFailsSometimes', result: 'Failed' }
193-
// { theCallStack: 'outerB:thisFailsSometimes' } implies 'outerB' was run first, then 'thisFailsSometimes'. See docstrings for more info.
194-
outerB()
225+
// Results in a metric: { theCallStack: 'thisThrows:failsDependingOnInput', result: 'Failed' }
226+
// { theCallStack: 'thisThrows:failsDependingOnInput' } implies 'thisThrows' was run first, then 'failsDependingOnInput'. See docstrings for more info.
227+
thisThrows()
195228
```
196229

197230
### Important Notes
@@ -216,25 +249,6 @@ outerB()
216249
c() // result: 'a:c', note that 'b' is not included
217250
```
218251

219-
- If you are using `run()` with a class method, you can also add the class to the entry for more context
220-
221-
```typescript
222-
class A {
223-
a() {
224-
return telemetry.my_Metric.run(() => this.b(), { functionId: { name: 'a', class: 'A' } })
225-
}
226-
227-
b() {
228-
return telemetry.my_Metric.run(() => asStringifiedStack(telemetry.getFunctionStack()), {
229-
functionId: { name: 'b', class: 'A' },
230-
})
231-
}
232-
}
233-
234-
const inst = new A()
235-
inst.a() // 'A#a,b'
236-
```
237-
238252
- If you do not want your `run()` to emit telemetry, set `emit: false` in the options
239253

240254
```typescript

packages/core/src/shared/telemetry/util.ts

Lines changed: 45 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -26,9 +26,10 @@ import { isValidationExemptMetric } from './exemptMetrics'
2626
import { isAmazonQ, isCloud9, isSageMaker } from '../../shared/extensionUtilities'
2727
import { isUuid, randomUUID } from '../crypto'
2828
import { ClassToInterfaceType } from '../utilities/tsUtils'
29-
import { FunctionEntry, type TelemetryTracer } from './spans'
29+
import { asStringifiedStack, FunctionEntry } from './spans'
3030
import { telemetry } from './telemetry'
3131
import { v5 as uuidV5 } from 'uuid'
32+
import { ToolkitError } from '../errors'
3233

3334
const legacySettingsTelemetryValueDisable = 'Disable'
3435
const legacySettingsTelemetryValueEnable = 'Enable'
@@ -365,9 +366,10 @@ export function getOperatingSystem(): OperatingSystem {
365366
}
366367
}
367368

369+
type TelemetryContextArgs = FunctionEntry & { emit?: boolean; errorCtx?: boolean }
368370
/**
369371
* Decorator that simply wraps the method with a non-emitting telemetry `run()`, automatically
370-
* `record()`ing the provided function id for later use by {@link TelemetryTracer.getFunctionStack()}
372+
* `record()`ing the provided function id for later use by TelemetryTracer.getFunctionStack()
371373
*
372374
* This saves us from needing to wrap the entire function:
373375
*
@@ -393,25 +395,60 @@ export function getOperatingSystem(): OperatingSystem {
393395
* }
394396
* }
395397
* ```
398+
*
399+
* @param opts.name The name of the function
400+
* @param opts.class The class name of the function
401+
* @param opts.emit Whether or not to emit the telemetry event (default: false)
402+
* @param opts.errorCtx Whether or not to add the error context to the error (default: false)
396403
*/
397-
export function withTelemetryContext(functionId: FunctionEntry) {
404+
export function withTelemetryContext(opts: TelemetryContextArgs) {
405+
const shouldErrorCtx = opts.errorCtx !== undefined ? opts.errorCtx : false
398406
function decorator<This, Args extends any[], Return>(
399407
originalMethod: (this: This, ...args: Args) => Return,
400408
_context: ClassMethodDecoratorContext // we dont need this currently but it keeps the compiler happy
401409
) {
402410
function decoratedMethod(this: This, ...args: Args): Return {
403411
return telemetry.function_call.run(
404-
() => {
405-
// DEVELOPERS: Set a breakpoint here and step in to it to debug the original function
406-
return originalMethod.call(this, ...args)
412+
(span) => {
413+
try {
414+
span.record({
415+
functionName: opts.name,
416+
className: opts.class,
417+
source: asStringifiedStack(telemetry.getFunctionStack()),
418+
})
419+
420+
// DEVELOPERS: Set a breakpoint here and step in and debug the original function
421+
const result = originalMethod.call(this, ...args)
422+
423+
if (result instanceof Promise) {
424+
return result.catch((e) => {
425+
if (shouldErrorCtx) {
426+
throw addContextToError(e, opts)
427+
}
428+
throw e
429+
}) as Return
430+
}
431+
return result
432+
} catch (e) {
433+
if (shouldErrorCtx) {
434+
throw addContextToError(e, opts)
435+
}
436+
throw e
437+
}
407438
},
408439
{
409-
emit: false,
410-
functionId: functionId,
440+
emit: opts.emit !== undefined ? opts.emit : false,
441+
functionId: { name: opts.name, class: opts.class },
411442
}
412443
)
413444
}
414445
return decoratedMethod
415446
}
416447
return decorator
448+
449+
function addContextToError(e: unknown, functionId: FunctionEntry) {
450+
return ToolkitError.chain(e, `ctx: ${functionId.name}`, {
451+
code: functionId.class,
452+
})
453+
}
417454
}

packages/core/src/shared/telemetry/vscodeTelemetry.json

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1137,6 +1137,10 @@
11371137
{
11381138
"type": "className",
11391139
"required": false
1140+
},
1141+
{
1142+
"type": "source",
1143+
"required": false
11401144
}
11411145
],
11421146
"passive": true

packages/core/src/test/shared/telemetry/spans.test.ts

Lines changed: 104 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -4,7 +4,7 @@
44
*/
55

66
import assert from 'assert'
7-
import { ToolkitError } from '../../../shared/errors'
7+
import { getErrorId, ToolkitError } from '../../../shared/errors'
88
import { asStringifiedStack, FunctionEntry, TelemetrySpan, TelemetryTracer } from '../../../shared/telemetry/spans'
99
import { MetricName, MetricShapes, telemetry } from '../../../shared/telemetry/telemetry'
1010
import { assertTelemetry, getMetrics, installFakeClock } from '../../testUtil'
@@ -575,19 +575,112 @@ describe('TelemetryTracer', function () {
575575
'A#a1,a2:B#b1,b2'
576576
)
577577
})
578+
})
579+
})
578580

579-
class TestEmit {
580-
@withTelemetryContext({ name: 'doesNotEmit', class: 'TestEmit' })
581-
doesNotEmit() {
582-
return
583-
}
581+
describe('withTelemetryContext', async function () {
582+
class TestEmit {
583+
@withTelemetryContext({ name: 'doesNotEmit', class: 'TestEmit' })
584+
doesNotEmit() {
585+
return
584586
}
585587

586-
it(`withTelemetryContext does not emit an event on its own`, function () {
587-
const inst = new TestEmit()
588-
inst.doesNotEmit()
589-
assertTelemetry('function_call', [])
590-
})
588+
@withTelemetryContext({ name: 'doesEmit', class: 'TestEmit', emit: false })
589+
doesEmit() {
590+
return this.doesEmitNested()
591+
}
592+
593+
@withTelemetryContext({ name: 'doesEmitNested', class: 'TestEmit', emit: true })
594+
doesEmitNested() {
595+
return
596+
}
597+
}
598+
599+
it(`does NOT emit an event if not explicitly set`, function () {
600+
const inst = new TestEmit()
601+
inst.doesNotEmit()
602+
assertTelemetry('function_call', [])
603+
})
604+
605+
it(`does emit an event on its own when explicitly set`, function () {
606+
const inst = new TestEmit()
607+
inst.doesEmit()
608+
assertTelemetry('function_call', [
609+
{
610+
functionName: 'doesEmitNested',
611+
className: 'TestEmit',
612+
source: 'TestEmit#doesEmit,doesEmitNested',
613+
},
614+
])
615+
})
616+
617+
class TestThrows {
618+
@withTelemetryContext({ name: 'throwsError', class: 'TestThrows', errorCtx: true })
619+
throwsError() {
620+
throw arbitraryError
621+
}
622+
623+
@withTelemetryContext({ name: 'throwsError', errorCtx: true })
624+
throwsErrorButNoClass() {
625+
throw arbitraryError
626+
}
627+
628+
@withTelemetryContext({ name: 'throwsError', errorCtx: true })
629+
async throwsAsyncError() {
630+
throw arbitraryError
631+
}
632+
633+
@withTelemetryContext({ name: 'throwsErrorButNoCtx', class: 'TestThrows' })
634+
throwsErrorButNoCtx() {
635+
throw arbitraryError
636+
}
637+
}
638+
const arbitraryError = new Error('arbitrary error')
639+
640+
it(`wraps errors with function id context`, async function () {
641+
const inst = new TestThrows()
642+
assert.throws(
643+
() => inst.throwsError(),
644+
(e) => {
645+
return (
646+
e instanceof ToolkitError &&
647+
getErrorId(e) === 'TestThrows' &&
648+
e.message === 'ctx: throwsError' &&
649+
e.cause === arbitraryError
650+
)
651+
}
652+
)
653+
assert.throws(
654+
() => inst.throwsErrorButNoClass(),
655+
(e) => {
656+
return (
657+
e instanceof ToolkitError &&
658+
getErrorId(e) === 'Error' &&
659+
e.message === 'ctx: throwsError' &&
660+
e.cause === arbitraryError
661+
)
662+
}
663+
)
664+
await assert.rejects(
665+
() => inst.throwsAsyncError(),
666+
(e) => {
667+
return (
668+
e instanceof ToolkitError &&
669+
getErrorId(e) === 'Error' &&
670+
e.message === 'ctx: throwsError' &&
671+
e.cause === arbitraryError
672+
)
673+
}
674+
)
675+
})
676+
677+
it('does not add error context by default', async function () {
678+
const inst = new TestThrows()
679+
680+
assert.throws(
681+
() => inst.throwsErrorButNoCtx(),
682+
(e) => e === arbitraryError
683+
)
591684
})
592685
})
593686

0 commit comments

Comments
 (0)