feat(trace): postprocess trace reporter for datadog

package.json

@@ -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",
@@ -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",

packages/next/trace/report/index.ts

@@ -10,7 +10,8 @@ type Reporter = {
     timestamp: number,
     id: SpanId,
     parentId?: SpanId,
-    attrs?: Object
+    attrs?: Object,
+    startTime?: number
   ) => void
 }
 
@@ -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
+      )
     )
   }
 }

packages/next/trace/report/to-json.ts

@@ -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
@@ -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')
@@ -161,6 +163,7 @@ const reportToLocalHost = (
     timestamp,
     duration,
     tags: attrs,
+    startTime,
   })
 }
 

packages/next/trace/trace.ts

@@ -22,6 +22,7 @@ export class Span {
   duration: number | null
   attrs: { [key: string]: any }
   status: SpanStatus
+  now: number
 
   _start: bigint
 
@@ -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
@@ -63,7 +70,8 @@ export class Span {
       Number(timestamp),
       this.id,
       this.parentId,
-      this.attrs
+      this.attrs,
+      this.now
     )
   }
 

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)
+  })