Add integration tests for SSI profiler activation

integration-tests/profiler/profiler.spec.js

@@ -21,20 +21,33 @@ if (process.platform !== 'win32') {
 }
 
 function checkProfiles (agent, proc, timeout,
-  expectedProfileTypes = DEFAULT_PROFILE_TYPES, expectBadExit = false, multiplicity = 1) {
+  expectedProfileTypes = DEFAULT_PROFILE_TYPES, expectBadExit = false, multiplicity = 1
+) {
+  return Promise.all([
+    processExitPromise(proc, timeout, expectBadExit),
+    expectProfileMessagePromise(agent, timeout, expectedProfileTypes, multiplicity)
+  ])
+}
+
+function expectProfileMessagePromise (agent, timeout,
+  expectedProfileTypes = DEFAULT_PROFILE_TYPES, multiplicity = 1
+) {
   const fileNames = expectedProfileTypes.map(type => `${type}.pprof`)
-  const resultPromise = agent.assertMessageReceived(({ headers, payload, files }) => {
-    assert.propertyVal(headers, 'host', `127.0.0.1:${agent.port}`)
-    assert.propertyVal(files[0], 'originalname', 'event.json')
-    const event = JSON.parse(files[0].buffer.toString())
-    assert.propertyVal(event, 'family', 'node')
-    assert.deepPropertyVal(event, 'attachments', fileNames)
-    for (const [index, fileName] of fileNames.entries()) {
-      assert.propertyVal(files[index + 1], 'originalname', fileName)
+  return agent.assertMessageReceived(({ headers, _, files }) => {
+    try {
+      assert.propertyVal(headers, 'host', `127.0.0.1:${agent.port}`)
+      assert.propertyVal(files[0], 'originalname', 'event.json')
+      const event = JSON.parse(files[0].buffer.toString())
+      assert.propertyVal(event, 'family', 'node')
+      assert.deepPropertyVal(event, 'attachments', fileNames)
+      for (const [index, fileName] of fileNames.entries()) {
+        assert.propertyVal(files[index + 1], 'originalname', fileName)
+      }
+    } catch (e) {
+      e.message += ` ${JSON.stringify({ headers, files })}`
+      throw e
     }
   }, timeout, multiplicity)
-
-  return Promise.all([processExitPromise(proc, timeout, expectBadExit), resultPromise])
 }
 
 function processExitPromise (proc, timeout, expectBadExit = false) {
@@ -73,6 +86,18 @@ async function getLatestProfile (cwd, pattern) {
   return { profile: Profile.decode(pprofUnzipped), encoded: pprofGzipped.toString('base64') }
 }
 
+function expectTimeout (messagePromise, allowErrors = false) {
+  return messagePromise.then(
+    () => {
+      throw new Error('Received unexpected message')
+    }, (e) => {
+      if (e.message !== 'timeout' && (!allowErrors || !e.message.startsWith('timeout, additionally:'))) {
+        throw e
+      }
+    }
+  )
+}
+
 async function gatherNetworkTimelineEvents (cwd, scriptFilePath, eventType, args) {
   const procStart = BigInt(Date.now() * 1000000)
   const proc = fork(path.join(cwd, scriptFilePath), args, {
@@ -142,6 +167,7 @@ describe('profiler', () => {
   let sandbox
   let cwd
   let profilerTestFile
+  let ssiTestFile
   let oomTestFile
   let oomEnv
   let oomExecArgv
@@ -151,6 +177,7 @@ describe('profiler', () => {
     sandbox = await createSandbox()
     cwd = sandbox.folder
     profilerTestFile = path.join(cwd, 'profiler/index.js')
+    ssiTestFile = path.join(cwd, 'profiler/ssi.js')
     oomTestFile = path.join(cwd, 'profiler/oom.js')
     oomExecArgv = ['--max-old-space-size=50']
   })
@@ -355,19 +382,10 @@ describe('profiler', () => {
           DD_PROFILING_ENABLED: 1
         }
       })
-      const checkTelemetry = agent.assertTelemetryReceived(({ headers, payload }) => {
-      }, 1000, 'generate-metrics')
+      const checkTelemetry = agent.assertTelemetryReceived(_ => {}, 1000, 'generate-metrics')
       // SSI telemetry is not supposed to have been emitted when DD_INJECTION_ENABLED is absent,
-      // so throw if telemetry callback was invoked  and do nothing if it timed out
-      const checkNoTelemetry = checkTelemetry.then(
-        () => {
-          throw new Error('Received unexpected metrics')
-        }, (e) => {
-          if (e.message !== 'timeout') {
-            throw e
-          }
-        })
-      return Promise.all([checkProfiles(agent, proc, timeout), checkNoTelemetry])
+      // so expect telemetry callback to time out
+      return Promise.all([checkProfiles(agent, proc, timeout), expectTimeout(checkTelemetry)])
     })
 
     it('records SSI telemetry on process exit', () => {
@@ -469,4 +487,67 @@ describe('profiler', () => {
       })
     }
   })
+
+  context('SSI heuristics', () => {
+    beforeEach(async () => {
+      agent = await new FakeAgent().start()
+    })
+
+    afterEach(async () => {
+      proc.kill()
+      await agent.stop()
+    })
+
+    describe('does not trigger for', () => {
+      it('does not trigger for a short-lived app that creates no spans', () => {
+        return heuristicsDoesNotTriggerFor([], false)
+      })
+
+      it('does not trigger for a short-lived app that creates a span', () => {
+        return heuristicsDoesNotTriggerFor(['create-span'], true)
+      })
+
+      it('does not trigger for a long-lived app that creates no spans', () => {
+        return heuristicsDoesNotTriggerFor(['long-lived'], false)
+      })
+    })
+
+    it('triggers for long-lived span-creating app', () => {
+      return checkProfiles(agent,
+        forkSsi(['create-span', 'long-lived']),
+        timeout,
+        DEFAULT_PROFILE_TYPES,
+        false,
+        // Will receive 2 messages: first one is for the trace, second one is for the profile. We
+        // only need the assertions in checkProfiles to succeed for the one with the profile.
+        2)
+    })
+  })
+
+  function forkSsi (args) {
+    return fork(ssiTestFile, args, {
+      cwd,
+      env: {
+        DD_TRACE_AGENT_PORT: agent.port,
+        DD_INJECTION_ENABLED: 'profiling',
+        DD_PROFILING_SSI_SHORT_LIVED_THRESHOLD: '1300'
+      }
+    })
+  }
+
+  function heuristicsDoesNotTriggerFor (args, allowTraceMessage) {
+    proc = fork(ssiTestFile, args, {
+      cwd,
+      env: {
+        DD_TRACE_AGENT_PORT: agent.port,
+        DD_INJECTION_ENABLED: 'profiling',
+        DD_PROFILING_SSI_SHORT_LIVED_THRESHOLD: '1300'
+      }
+    })
+
+    return Promise.all([
+      processExitPromise(proc, timeout, false),
+      expectTimeout(expectProfileMessagePromise(agent, 1500), allowTraceMessage)
+    ])
+  }
 })

integration-tests/profiler/ssi.js

@@ -0,0 +1,21 @@
+'use strict'
+
+const DDTrace = require('dd-trace')
+
+const tracer = DDTrace.init()
+
+async function run () {
+  const tasks = []
+  if (process.argv.includes('create-span')) {
+    tasks.push(tracer.trace('woo', _ => {
+      return new Promise(setImmediate)
+    }))
+  }
+  if (process.argv.includes('long-lived')) {
+    const shortLivedThreshold = Number(process.env.DD_PROFILING_SSI_SHORT_LIVED_THRESHOLD)
+    tasks.push(new Promise(resolve => setTimeout(resolve, shortLivedThreshold + 200)))
+  }
+  await Promise.all(tasks)
+}
+
+tracer.profilerStarted().then(run)

packages/dd-trace/src/config.js

@@ -490,6 +490,7 @@ class Config {
     this._setValue(defaults, 'profiling.sourceMap', true)
     this._setValue(defaults, 'profiling.ssi', false)
     this._setValue(defaults, 'profiling.heuristicsEnabled', false)
+    this._setValue(defaults, 'profiling.shortLivedThreshold', undefined)
     this._setValue(defaults, 'protocolVersion', '0.4')
     this._setValue(defaults, 'queryStringObfuscation', qsRegex)
     this._setValue(defaults, 'remoteConfig.enabled', true)
@@ -560,6 +561,7 @@ class Config {
       DD_PROFILING_ENABLED,
       DD_PROFILING_EXPORTERS,
       DD_PROFILING_SOURCE_MAP,
+      DD_PROFILING_SSI_SHORT_LIVED_THRESHOLD,
       DD_REMOTE_CONFIGURATION_ENABLED,
       DD_REMOTE_CONFIG_POLL_INTERVAL_SECONDS,
       DD_RUNTIME_METRICS_ENABLED,
@@ -670,6 +672,10 @@ class Config {
       if (DD_INJECTION_ENABLED.split(',').includes('profiling')) {
         this._setBoolean(env, 'profiling.heuristicsEnabled', true)
       }
+      if (DD_PROFILING_SSI_SHORT_LIVED_THRESHOLD) {
+        // This is only used in testing to not have to wait 30s
+        this._setValue(env, 'profiling.shortLivedThreshold', Number(DD_PROFILING_SSI_SHORT_LIVED_THRESHOLD))
+      }
     }
 
     this._setString(env, 'protocolVersion', DD_TRACE_AGENT_PROTOCOL_VERSION)