Skip to content

Commit

Permalink
feat(trace): postprocess trace reporter for datadog (#35032)
Browse files Browse the repository at this point in the history
* feat(trace): include clocktime for span

* build(package): bump up devdependencies

* feat(trace): postprocess trace reporter for datadog

* build(package): update precompile pkgs

* update compiled

Co-authored-by: JJ Kasper <jj@jjsweb.site>
  • Loading branch information
kwonoj and ijjk committed Mar 8, 2022
1 parent 292636d commit 8d0561e
Show file tree
Hide file tree
Showing 11 changed files with 454 additions and 19 deletions.
2 changes: 2 additions & 0 deletions package.json
Expand Up @@ -98,6 +98,7 @@
"critters": "0.0.6",
"cross-env": "6.0.3",
"cross-spawn": "6.0.5",
"dd-trace": "2.3.0",
"es5-ext": "0.10.53",
"escape-string-regexp": "2.0.0",
"eslint": "7.24.0",
Expand All @@ -110,6 +111,7 @@
"faker": "5.5.3",
"faunadb": "2.6.1",
"firebase": "7.14.5",
"flat": "5.0.2",
"fs-extra": "9.0.0",
"get-port": "5.1.1",
"glob": "7.1.6",
Expand Down
2 changes: 1 addition & 1 deletion packages/next/compiled/@vercel/nft/index.js

Large diffs are not rendered by default.

2 changes: 1 addition & 1 deletion packages/next/compiled/crypto-browserify/index.js

Large diffs are not rendered by default.

2 changes: 1 addition & 1 deletion packages/next/compiled/p-limit/index.js

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

2 changes: 1 addition & 1 deletion packages/next/compiled/stream-browserify/index.js

Large diffs are not rendered by default.

2 changes: 1 addition & 1 deletion packages/next/compiled/stream-http/index.js

Large diffs are not rendered by default.

16 changes: 13 additions & 3 deletions packages/next/trace/report/index.ts
Expand Up @@ -10,7 +10,8 @@ type Reporter = {
timestamp: number,
id: SpanId,
parentId?: SpanId,
attrs?: Object
attrs?: Object,
startTime?: number
) => void
}

Expand All @@ -31,10 +32,19 @@ class MultiReporter implements Reporter {
timestamp: number,
id: SpanId,
parentId?: SpanId,
attrs?: Object
attrs?: Object,
startTime?: number
) {
this.reporters.forEach((reporter) =>
reporter.report(spanName, duration, timestamp, id, parentId, attrs)
reporter.report(
spanName,
duration,
timestamp,
id,
parentId,
attrs,
startTime
)
)
}
}
Expand Down
5 changes: 4 additions & 1 deletion packages/next/trace/report/to-json.ts
Expand Up @@ -19,6 +19,7 @@ type Event = {
duration: number
localEndpoint?: typeof localEndpoint
tags?: Object
startTime?: number
}

// Batch events as zipkin allows for multiple events to be sent in one go
Expand Down Expand Up @@ -121,7 +122,8 @@ const reportToLocalHost = (
timestamp: number,
id: number,
parentId?: number,
attrs?: Object
attrs?: Object,
startTime?: number
) => {
const distDir = traceGlobals.get('distDir')
const phase = traceGlobals.get('phase')
Expand Down Expand Up @@ -161,6 +163,7 @@ const reportToLocalHost = (
timestamp,
duration,
tags: attrs,
startTime,
})
}

Expand Down
10 changes: 9 additions & 1 deletion packages/next/trace/trace.ts
Expand Up @@ -22,6 +22,7 @@ export class Span {
duration: number | null
attrs: { [key: string]: any }
status: SpanStatus
now: number

_start: bigint

Expand All @@ -43,6 +44,12 @@ export class Span {
this.status = SpanStatus.Started
this.id = getId()
this._start = startTime || process.hrtime.bigint()
// hrtime cannot be used to reconstruct tracing span's actual start time
// since it does not have relation to clock time:
// `These times are relative to an arbitrary time in the past, and not related to the time of day and therefore not subject to clock drift`
// https://nodejs.org/api/process.html#processhrtimetime
// Capturing current datetime as additional metadata for external reconstruction.
this.now = Date.now()
}

// Durations are reported as microseconds. This gives 1000x the precision
Expand All @@ -63,7 +70,8 @@ export class Span {
Number(timestamp),
this.id,
this.parentId,
this.attrs
this.attrs,
this.now
)
}

Expand Down
177 changes: 177 additions & 0 deletions scripts/trace-dd.mjs
@@ -0,0 +1,177 @@
import { createReadStream } from 'fs'
import { createInterface } from 'readline'
import path from 'path'
import Tracer from 'dd-trace'
import flat from 'flat'

const cleanFilename = (filename) => {
if (filename.includes('&absolutePagePath=')) {
filename =
'page ' +
decodeURIComponent(
filename.replace(/.+&absolutePagePath=/, '').slice(0, -1)
)
}
filename = filename.replace(/.+!(?!$)/, '')
return filename
}

const getPackageName = (filename) => {
const match = /.+[\\/]node_modules[\\/]((?:@[^\\/]+[\\/])?[^\\/]+)/.exec(
cleanFilename(filename)
)
return match && match[1]
}

/**
* Create, reports spans recursively with its inner child spans.
*/
const reportSpanRecursively = (tracer, trace, parentSpan) => {
// build-* span contains tags with path to the modules, trying to clean up if possible
const isBuildModule = trace.name.startsWith('build-module-')
if (isBuildModule) {
trace.packageName = getPackageName(trace.tags.name)
// replace name to cleaned up pkg name
trace.tags.name = trace.packageName
if (trace.children) {
const queue = [...trace.children]
trace.children = []
for (const e of queue) {
if (e.name.startsWith('build-module-')) {
const pkgName = getPackageName(e.tags.name)
if (!trace.packageName || pkgName !== trace.packageName) {
trace.children.push(e)
} else {
if (e.children) queue.push(...e.children)
}
}
}
}
}

/**
* interface TraceEvent {
* traceId: string;
* parentId: number;
* name: string;
* id: number;
* startTime: number;
* timestamp: number;
* duration: number;
* tags: Record<string, any>
* }
*/
let span = tracer.startSpan(trace.name, {
startTime: trace.startTime,
childOf: parentSpan,
tags: Object.keys(trace?.tags).length > 0 ? trace?.tags : undefined,
})

// Spans should be reported in chronological order
trace.children?.sort((a, b) => a.startTime - b.startTime)
trace.children?.forEach((childTrace) =>
reportSpanRecursively(tracer, childTrace, span)
)

span.finish(trace.startTime + trace.duration / 1000)
return span
}

/**
* Read generated trace from file system, augment & sent it to the remote tracer.
*/
const collectTraces = async (filePath, metadata) => {
const tracer = Tracer.init({
tags: metadata,
// Setting external env variable `DD_TRACE_DEBUG=true` will emit this log
logLevel: 'error',
// TODO: this is due to generated trace have excessive numbers of spans
// for build-module-*, using default flush causes overflow to the agent.
flushInterval: 20,
flushMinSpans: 10,
})

const readLineInterface = createInterface({
input: createReadStream(filePath),
crlfDelay: Infinity,
})

const traces = new Map()
const rootTraces = []

// Input trace file contains newline-seperated sets of traces, where each line is valid JSON
// type of Array<TraceEvent>. Read it line-by-line to manually reconstruct trace trees.
//
// We have to read through end of the trace -
// Trace events in the input file can appear out of order, so we need to remodel the shape of the span tree before reporting
for await (const line of readLineInterface) {
JSON.parse(line).forEach((trace) => traces.set(trace.id, trace))
}

// Link inner, child spans to the parents to reconstruct span with correct relations
for (const event of traces.values()) {
if (event.parentId) {
event.parent = traces.get(event.parentId)
if (event.parent) {
if (!event.parent.children) event.parent.children = []
event.parent.children.push(event)
}
}

if (!event.parent) {
rootTraces.push(event)
}
}

for (const trace of rootTraces) {
reportSpanRecursively(tracer, trace)
}
}

/**
* Naively validate, collect necessary args.
*/
const validateArgs = async () => {
const { DD_ENV, DD_SERVICE } = process.env

if (!DD_ENV || !DD_SERVICE) {
throw new Error(
`Could not find proper enviroment variables. Ensure to set DD_ENV / DD_SERVICE`
)
}

// Collect necessary default metadata. Script should pass cli args as in order of
// - trace file to read
// - which command ran to generated trace (`build`, `dev`, ...)
// - short sha for the commit
// - path to next.config.js (optional)
const [, , traceFilePath, command, commit, configFilePath] = process.argv
const config = configFilePath
? (await import(path.resolve(process.cwd(), configFilePath))).default
: {}

if (!traceFilePath || !command || !commit) {
throw new Error(
`Cannot collect traces without necessary metadata.
Try to run script with below args:
node trace-dd.mjs tracefilepath command commit [configfilepath]`
)
}

const metadata = {
command,
commit,
// TODO: it is unclear, but some of nested object seems not supported
nextjs_config: flat.flatten(config),
}

return [traceFilePath, metadata]
}

validateArgs()
.then(([traceFilePath, metadata]) => collectTraces(traceFilePath, metadata))
.catch((e) => {
console.error(`Failed to collect traces`)
console.error(e)
})

0 comments on commit 8d0561e

Please sign in to comment.