Skip to content

Commit 8cca684

Browse files
astuyveastuyve
authored
Aj/cold start tracing (#336)
* feat: Cold Start Tracing support * feat: Add filename to cold start spans * feat: Break out cold start tracer to class. Add specs. Prettier. * feat: Expose minColdStartDuration and coldStartTracing config * feat: Reduce number of open spans * feat: Remove unneeded await * feat: integrations * feat: lint * feat: tsconfig * feat: Optionaly skip libraries from cold start spans * feat: lint
1 parent e247c98 commit 8cca684

18 files changed

+621
-13
lines changed

‎integration_tests/snapshots/logs/esm_node12.log

Lines changed: 6 additions & 6 deletions
Large diffs are not rendered by default.

‎integration_tests/snapshots/logs/process-input-traced_node12.log

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -136,6 +136,28 @@ START
136136
"start":XXXX,
137137
"duration":XXXX,
138138
"service": "integration-tests-js-XXXX-process-input-traced_node12"
139+
},
140+
{
141+
"trace_id":"XXXX",
142+
"span_id":"XXXX",
143+
"parent_id":"XXXX",
144+
"name": "aws.lambda.load",
145+
"resource": "integration-tests-js-XXXX-process-input-traced_node12",
146+
"error": 0,
147+
"meta": {
148+
"service": "aws.lambda",
149+
"runtime-id":"XXXX",
150+
"operation_name": "aws.lambda.require",
151+
"resource_names": "integration-tests-js-XXXX-process-input-traced_node12",
152+
"language": "javascript"
153+
},
154+
"metrics": {
155+
"process_id":XXXX,
156+
"_sampling_priority_v1": 1
157+
},
158+
"start":XXXX,
159+
"duration":XXXX,
160+
"service": "integration-tests-js-XXXX-process-input-traced_node12"
139161
}
140162
]
141163
]

‎integration_tests/snapshots/logs/process-input-traced_node14.log

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -136,6 +136,28 @@ START
136136
"start":XXXX,
137137
"duration":XXXX,
138138
"service": "integration-tests-js-XXXX-process-input-traced_node14"
139+
},
140+
{
141+
"trace_id":"XXXX",
142+
"span_id":"XXXX",
143+
"parent_id":"XXXX",
144+
"name": "aws.lambda.load",
145+
"resource": "integration-tests-js-XXXX-process-input-traced_node14",
146+
"error": 0,
147+
"meta": {
148+
"service": "aws.lambda",
149+
"runtime-id":"XXXX",
150+
"operation_name": "aws.lambda.require",
151+
"resource_names": "integration-tests-js-XXXX-process-input-traced_node14",
152+
"language": "javascript"
153+
},
154+
"metrics": {
155+
"process_id":XXXX,
156+
"_sampling_priority_v1": 1
157+
},
158+
"start":XXXX,
159+
"duration":XXXX,
160+
"service": "integration-tests-js-XXXX-process-input-traced_node14"
139161
}
140162
]
141163
]

‎integration_tests/snapshots/logs/process-input-traced_node16.log

Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -140,6 +140,29 @@ START
140140
"start":XXXX,
141141
"duration":XXXX,
142142
"service": "integration-tests-js-XXXX-process-input-traced_node16"
143+
},
144+
{
145+
"trace_id":"XXXX",
146+
"span_id":"XXXX",
147+
"parent_id":"XXXX",
148+
"name": "aws.lambda.load",
149+
"resource": "integration-tests-js-XXXX-process-input-traced_node16",
150+
"error": 0,
151+
"meta": {
152+
"service": "aws.lambda",
153+
"version": "1.0.0",
154+
"runtime-id":"XXXX",
155+
"operation_name": "aws.lambda.require",
156+
"resource_names": "integration-tests-js-XXXX-process-input-traced_node16",
157+
"language": "javascript"
158+
},
159+
"metrics": {
160+
"process_id":XXXX,
161+
"_sampling_priority_v1": 1
162+
},
163+
"start":XXXX,
164+
"duration":XXXX,
165+
"service": "integration-tests-js-XXXX-process-input-traced_node16"
143166
}
144167
]
145168
]

‎integration_tests/snapshots/logs/process-input-traced_node18.log

Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -140,6 +140,29 @@ START
140140
"start":XXXX,
141141
"duration":XXXX,
142142
"service": "integration-tests-js-XXXX-process-input-traced_node18"
143+
},
144+
{
145+
"trace_id":"XXXX",
146+
"span_id":"XXXX",
147+
"parent_id":"XXXX",
148+
"name": "aws.lambda.load",
149+
"resource": "integration-tests-js-XXXX-process-input-traced_node18",
150+
"error": 0,
151+
"meta": {
152+
"service": "aws.lambda",
153+
"version": "1.0.0",
154+
"runtime-id":"XXXX",
155+
"operation_name": "aws.lambda.require",
156+
"resource_names": "integration-tests-js-XXXX-process-input-traced_node18",
157+
"language": "javascript"
158+
},
159+
"metrics": {
160+
"process_id":XXXX,
161+
"_sampling_priority_v1": 1
162+
},
163+
"start":XXXX,
164+
"duration":XXXX,
165+
"service": "integration-tests-js-XXXX-process-input-traced_node18"
143166
}
144167
]
145168
]

‎integration_tests/snapshots/logs/status-code-500s_node12.log

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -96,6 +96,28 @@ START
9696
"duration":XXXX,
9797
"service": "aws.lambda",
9898
"type": "serverless"
99+
},
100+
{
101+
"trace_id":"XXXX",
102+
"span_id":"XXXX",
103+
"parent_id":"XXXX",
104+
"name": "aws.lambda.load",
105+
"resource": "integration-tests-js-XXXX-status-code-500s_node12",
106+
"error": 0,
107+
"meta": {
108+
"service": "aws.lambda",
109+
"runtime-id":"XXXX",
110+
"operation_name": "aws.lambda.require",
111+
"resource_names": "integration-tests-js-XXXX-status-code-500s_node12",
112+
"language": "javascript"
113+
},
114+
"metrics": {
115+
"process_id":XXXX,
116+
"_sampling_priority_v1": 1
117+
},
118+
"start":XXXX,
119+
"duration":XXXX,
120+
"service": "integration-tests-js-XXXX-status-code-500s_node12"
99121
}
100122
]
101123
]

‎integration_tests/snapshots/logs/status-code-500s_node14.log

Lines changed: 23 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -96,6 +96,28 @@ START
9696
"duration":XXXX,
9797
"service": "aws.lambda",
9898
"type": "serverless"
99+
},
100+
{
101+
"trace_id":"XXXX",
102+
"span_id":"XXXX",
103+
"parent_id":"XXXX",
104+
"name": "aws.lambda.load",
105+
"resource": "integration-tests-js-XXXX-status-code-500s_node14",
106+
"error": 0,
107+
"meta": {
108+
"service": "aws.lambda",
109+
"runtime-id":"XXXX",
110+
"operation_name": "aws.lambda.require",
111+
"resource_names": "integration-tests-js-XXXX-status-code-500s_node14",
112+
"language": "javascript"
113+
},
114+
"metrics": {
115+
"process_id":XXXX,
116+
"_sampling_priority_v1": 1
117+
},
118+
"start":XXXX,
119+
"duration":XXXX,
120+
"service": "integration-tests-js-XXXX-status-code-500s_node14"
99121
}
100122
]
101123
]
@@ -191,6 +213,7 @@ START
191213
}
192214
END Duration: XXXX ms Memory Used: XXXX MB
193215
START
216+
END Duration: XXXX ms Memory Used: XXXX MB
194217
{
195218
"e": XXXX,
196219
"m": "aws.lambda.enhanced.invocations",
@@ -277,4 +300,3 @@ START
277300
]
278301
]
279302
}
280-
END Duration: XXXX ms Memory Used: XXXX MB

‎integration_tests/snapshots/logs/status-code-500s_node16.log

Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -98,6 +98,29 @@ START
9898
"duration":XXXX,
9999
"service": "aws.lambda",
100100
"type": "serverless"
101+
},
102+
{
103+
"trace_id":"XXXX",
104+
"span_id":"XXXX",
105+
"parent_id":"XXXX",
106+
"name": "aws.lambda.load",
107+
"resource": "integration-tests-js-XXXX-status-code-500s_node16",
108+
"error": 0,
109+
"meta": {
110+
"service": "aws.lambda",
111+
"version": "1.0.0",
112+
"runtime-id":"XXXX",
113+
"operation_name": "aws.lambda.require",
114+
"resource_names": "integration-tests-js-XXXX-status-code-500s_node16",
115+
"language": "javascript"
116+
},
117+
"metrics": {
118+
"process_id":XXXX,
119+
"_sampling_priority_v1": 1
120+
},
121+
"start":XXXX,
122+
"duration":XXXX,
123+
"service": "integration-tests-js-XXXX-status-code-500s_node16"
101124
}
102125
]
103126
]

‎integration_tests/snapshots/logs/status-code-500s_node18.log

Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -98,6 +98,29 @@ START
9898
"duration":XXXX,
9999
"service": "aws.lambda",
100100
"type": "serverless"
101+
},
102+
{
103+
"trace_id":"XXXX",
104+
"span_id":"XXXX",
105+
"parent_id":"XXXX",
106+
"name": "aws.lambda.load",
107+
"resource": "integration-tests-js-XXXX-status-code-500s_node18",
108+
"error": 0,
109+
"meta": {
110+
"service": "aws.lambda",
111+
"version": "1.0.0",
112+
"runtime-id":"XXXX",
113+
"operation_name": "aws.lambda.require",
114+
"resource_names": "integration-tests-js-XXXX-status-code-500s_node18",
115+
"language": "javascript"
116+
},
117+
"metrics": {
118+
"process_id":XXXX,
119+
"_sampling_priority_v1": 1
120+
},
121+
"start":XXXX,
122+
"duration":XXXX,
123+
"service": "integration-tests-js-XXXX-status-code-500s_node18"
101124
}
102125
]
103126
]

‎src/index.ts

Lines changed: 18 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@ import {
77
MetricsListener,
88
} from "./metrics";
99
import { TraceConfig, TraceHeaders, TraceListener } from "./trace";
10+
import { subscribeToDC } from "./runtime";
1011
import {
1112
logDebug,
1213
logError,
@@ -36,6 +37,9 @@ export const traceExtractorEnvVar = "DD_TRACE_EXTRACTOR";
3637
export const defaultSiteURL = "datadoghq.com";
3738
export const encodeAuthorizerContextEnvVar = "DD_ENCODE_AUTHORIZER_CONTEXT";
3839
export const decodeAuthorizerContextEnvVar = "DD_DECODE_AUTHORIZER_CONTEXT";
40+
export const coldStartTracingEnvVar = "DD_COLD_START_TRACING";
41+
export const minColdStartTraceDurationEnvVar = "DD_MIN_COLD_START_DURATION";
42+
export const coldStartTraceSkipLibEnvVar = "DD_COLD_START_TRACE_SKIP_LIB";
3943

4044
interface GlobalConfig {
4145
/**
@@ -75,11 +79,16 @@ export const defaultConfig: Config = {
7579
mergeDatadogXrayTraces: false,
7680
shouldRetryMetrics: false,
7781
siteURL: "",
82+
minColdStartTraceDuration: 3,
83+
coldStartTraceSkipLib: "",
7884
} as const;
7985

8086
let currentMetricsListener: MetricsListener | undefined;
8187
let currentTraceListener: TraceListener | undefined;
8288

89+
if (getEnvValue(coldStartTracingEnvVar, "true")) {
90+
subscribeToDC();
91+
}
8392
/**
8493
* Wraps your AWS lambda handler functions to add tracing/metrics support
8594
* @param handler A lambda handler function.
@@ -120,7 +129,7 @@ export function datadog<TEvent, TResult>(
120129
currentTraceListener = traceListener;
121130

122131
try {
123-
await traceListener.onStartInvocation(event, context);
132+
traceListener.onStartInvocation(event, context);
124133
await metricsListener.onStartInvocation(event);
125134
if (finalConfig.enhancedMetrics) {
126135
incrementInvocationsMetric(metricsListener, context);
@@ -287,6 +296,14 @@ function getConfig(userConfig?: Partial<Config>): Config {
287296
config.decodeAuthorizerContext = result === "true";
288297
}
289298

299+
if (userConfig === undefined || userConfig.minColdStartTraceDuration === undefined) {
300+
config.minColdStartTraceDuration = Number(getEnvValue(minColdStartTraceDurationEnvVar, "3"));
301+
}
302+
303+
if (userConfig === undefined || userConfig.minColdStartTraceDuration === undefined) {
304+
config.coldStartTraceSkipLib = getEnvValue(coldStartTraceSkipLibEnvVar, "./opentracing/tracer");
305+
}
306+
290307
return config;
291308
}
292309

‎src/runtime/index.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1 +1,2 @@
11
export { load, loadSync } from "./user-function";
2+
export { subscribeToDC, getTraceTree, RequireNode } from "./require-tracer"

‎src/runtime/require-tracer.spec.ts

Lines changed: 29 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,29 @@
1+
import { subscribeToDC, getTraceTree, RequireNode } from "./require-tracer";
2+
const dc = require('diagnostics_channel')
3+
4+
describe('require-tracer', () => {
5+
it('generates a trace tree', () => {
6+
subscribeToDC()
7+
const moduleLoadStartChannel = dc.channel('dd-trace:moduleLoadStart')
8+
const moduleLoadEndChannel = dc.channel('dd-trace:moduleLoadEnd')
9+
10+
// require('myLibrary')
11+
moduleLoadStartChannel.publish({
12+
request: 'myLibrary'
13+
})
14+
// require('myChildLibrary')
15+
moduleLoadStartChannel.publish({
16+
request: 'myChildLibrary'
17+
})
18+
moduleLoadEndChannel.publish()
19+
moduleLoadEndChannel.publish()
20+
const res = getTraceTree()
21+
expect(res).toBeDefined
22+
expect(res[0].id).toBe('myLibrary')
23+
const resChildren = res[0].children as RequireNode[]
24+
expect(resChildren).toHaveLength(1)
25+
const resChild = resChildren.pop() as RequireNode
26+
expect(resChild.id).toBe('myChildLibrary')
27+
})
28+
29+
})

‎src/runtime/require-tracer.ts

Lines changed: 58 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,58 @@
1+
const dc = require('diagnostics_channel')
2+
3+
export class RequireNode {
4+
public id: string
5+
public filename: string
6+
public startTime: number
7+
public endTime: number
8+
public children: RequireNode[]
9+
10+
constructor(id: string, filename: string, startTime: number) {
11+
this.id = id
12+
this.filename = filename
13+
this.startTime = startTime
14+
this.endTime = startTime
15+
this.children = []
16+
}
17+
18+
public set setEnd(endTime: number) {
19+
this.endTime = endTime
20+
}
21+
}
22+
23+
const moduleLoadStartChannel = dc.channel('dd-trace:moduleLoadStart')
24+
const moduleLoadEndChannel = dc.channel('dd-trace:moduleLoadEnd')
25+
const rootNodes: RequireNode[] = []
26+
27+
const requireStack: RequireNode[] = []
28+
const pushNode = (data: any) => {
29+
const startTime = Date.now()
30+
31+
const reqNode = new RequireNode(data.request, data.filename, startTime)
32+
const maybeParent = requireStack[requireStack.length - 1]
33+
34+
if (maybeParent) {
35+
maybeParent.children.push(reqNode)
36+
}
37+
requireStack.push(reqNode)
38+
}
39+
40+
const popNode = () => {
41+
const endTime = Date.now()
42+
const reqNode = requireStack.pop()
43+
if (reqNode){
44+
reqNode.endTime = endTime
45+
}
46+
if (requireStack.length <= 0 && reqNode) {
47+
rootNodes.push(reqNode)
48+
}
49+
}
50+
51+
export const subscribeToDC = () => {
52+
moduleLoadStartChannel.subscribe(pushNode)
53+
moduleLoadEndChannel.subscribe(popNode)
54+
}
55+
56+
export const getTraceTree = (): RequireNode[] => {
57+
return rootNodes
58+
}

0 commit comments

Comments
 (0)