Plugins consume too much CPU

kaievns commented 4 years ago

Describe the bug Ohi there, I've been struggling to instrument an express/mongo-core app with dd-trace for a few days now. I looked up the issues history and couldnt find anything similar, and so I thought I'd report this, maybe I'm doing this wrong, or maybe there is a problem I'm not aware of.

Basically, I have a dozen microservices, fairly simple RESTful APIs, pretty much straight up express+mongo-core applications. All of this runs in kubernetes on GCP. The kubes side is all hooked up and seems to work fine, but, on the node application side I'm seeing a weird behavior where CPU usage spikes up 10x when I enable the plugins.

Here is how the code looks like:

  const tracer = require('dd-trace');
  tracer.init({
    hostname: process.env.DD_AGENT_HOST,
    service: process.env.SERVICE_NAME,
    env: process.env.ENVIRONMENT,
    runtimeMetrics: true,
    analytics: true
  });

This creates a spike in CPU utilisation, see other services with plugins disabled, versus the CORE service that has plugins enabled

If i disable all plugins by adding plugins: false it falls back to normality, but as soon as I try to activate any plugins, say like so:

  const tracer = require('dd-trace');
  tracer.init({
    hostname: process.env.DD_AGENT_HOST,
    service: process.env.SERVICE_NAME,
    env: process.env.ENVIRONMENT,
    runtimeMetrics: true,
    analytics: true,
    plugins: false
  });
  tracer.use('http');

It jumps back up to 10x CPU usage.

Any ideas what's causing this? Anything I can do about it?

Thanks

Environment microservices in kubernetes

Operation system: docker + alpine. tried buster-slim, and got the same result
Node version: I tried 13.3, 13.14, 14.3 all cause the same exact issue. 14.3 seems to have slightly less spike but it is still in the 10x range
Tracer version: 0.20.3 and tried 0.21
Agent version: 7.19.0 - i believe

kaievns commented 4 years ago

after further investigation it seems like the http plugin might be the culprit. when i activate just the fs plugin like so, everything seems normal:

  const tracer = require('dd-trace');
  tracer.init({
    hostname: process.env.DD_AGENT_HOST,
    service: process.env.SERVICE_NAME,
    env: process.env.ENVIRONMENT,
    runtimeMetrics: true,
    analytics: true,
    plugins: false
  });
  tracer.use('fs');

but if i replace fs with http it goes haywire again

rochdev commented 4 years ago

For this kind of issue, I would recommend to open an issue with support and also DM me (rochdev) on our public Slack since we will need to look into your account to check the traces and runtime metrics.

kaievns commented 4 years ago

maybe you could point me in the right direction there how i could debug it on my end? it seems weird, as we don't really use anything unusual in our services, and i would expect it would just work

rochdev commented 4 years ago

Is the additional CPU usage increasing over time or is it constant for the lifetime of the process?

A few things worth checking/trying:

I see you have runtime metrics enabled. Comparing these metrics with and without the plugin could help determine if there's something off. Runtime metrics have a dedicated dashboard and are also available in the explorer with the runtime.node. prefix.
Trying the tracer with the scope option set to noop or using DD_CONTEXT_PROPAGATION=false to see if the issue is the scope manager.
Trying the tracer with the trackAsyncScope option set to false. This disables a workaround we have for a limitation in Node that may not affect you if you are using native promises.
Given how drastic the impact is, the hot spot should be clearly visible with a profiler. I would recommend trying to run the app with node --prof and analyze the outputted profile.

Let me know of any findings from the above.

kaievns commented 4 years ago

excellent, thanks Roch, I'll poke at those with a stick an see what falls out of it

kaievns commented 4 years ago

so, i poked at it a bit today the overall result goes like this:

runtime mentrics don't show much i order to debug the problem, it's just a total CPU/memory usage on the box
setting scope: 'noop' didnt do anything
setting trackAsyncScope: false drops idle usage from 100mc to ~50mc (5x above the baseline)

i'm trying to pull something from the node --prof at the moment, see if i can give you some traces

kaievns commented 4 years ago

Okay here is the profiler file i got from node on an idle application running on localhost (within the same docker environment as prod) does it look like anything to you?

Testing v8 version different from logging version
Statistical profiling result from isolate-0x55b898f4d280-1-v8.log, (2588 ticks, 1608 unaccounted, 0 excluded).

 [Shared libraries]:
   ticks  total  nonlib   name
    914   35.3%          /lib/ld-musl-x86_64.so.1
     26    1.0%          /usr/lib/libstdc++.so.6.0.27
      4    0.2%          /usr/local/bin/node
      2    0.1%          [vdso]

 [JavaScript]:
   ticks  total  nonlib   name
      7    0.3%    0.4%  LazyCompile: *resolve path.js:973:10
      5    0.2%    0.3%  LazyCompile: *normalizeString path.js:52:25
      4    0.2%    0.2%  RegExp: if\s*\(([^)]+)\)\s*\{\s*\}\s*else(?!\s*if)
      3    0.1%    0.2%  LazyCompile: *getStrPrefixes /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:5:25
      3    0.1%    0.2%  LazyCompile: *getArrayPrefixes /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:39:27
      2    0.1%    0.1%  LazyCompile: *getMapPrefixes /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:56:25
      2    0.1%    0.1%  LazyCompile: *Module._nodeModulePaths internal/modules/cjs/loader.js:748:37
      1    0.0%    0.1%  RegExp: else\s*{\s*}
      1    0.0%    0.1%  RegExp: ^((?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])[.]){3}(?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])$
      1    0.0%    0.1%  RegExp: ^((?:@[^/\\%]+\/)?[^./\\%][^/\\%]*)(\/.*)?$
      1    0.0%    0.1%  RegExp: ^((?:(?:[0-9a-fA-F]{1,4}):){7}(?:(?:[0-9a-fA-F]{1,4})|:)|(?:(?:[0-9a-fA-F]{1,4}):){6}(?:((?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])[.]){3}(?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])|:(?:[0-9a-fA-F]{1,4})|:)|(?:(?:[0-9a-fA-F]{1,4}):){5}(?::((?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])[.]){3}(?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])|(:(?:[0-9a-fA-F]{1,4})){1,2}|:)|(?:(?:[0-9a-fA-F]{1,4}):){4}(?:(:(?:[0-9a-fA-F]{1,4})){0,1}:((?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])[.]){3}(?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])|(:(?:[0-9a-fA-F]{1,4})){1,3}|:)|(?:(?:[0-9a-fA-F]{1,4}):){3}(?:(:(?:[0-9a-fA-F]{1,4})){0,2}:((?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])[.]){3}(?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])|(:(?:[0-9a-fA-F]{1,4})){1,4}|:)|(?:(?:[0-9a-fA-F]{1,4}):){2}(?:(:(?:[0-9a-fA-F]{1,4})){0,3}:((?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])[.]){3}(?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])|(:(?:[0-9a-fA-F]{1,4})){1,5}|:)|(?:(?:[0-9a-fA-F]{1,4}):){1}(?:(:(?:[0-9a-fA-F]{1,4})){0,4}:((?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])[.]){3}(?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])|(:(?:[0-9a-fA-F]{1,4})){1,6}|:)|(?::((?::(?:[0-9a-fA-F]{1,4})){0,5}:((?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])[.]){3}(?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])|(?::(?:[0-9a-fA-F]{1,4})){1,7}|:)))(%[0-9a-zA-Z]{1,})?$
      1    0.0%    0.1%  RegExp: [^v.]errors
      1    0.0%    0.1%  LazyCompile: *realpathSync fs.js:1570:22
      1    0.0%    0.1%  LazyCompile: *dirname path.js:1127:10
      1    0.0%    0.1%  LazyCompile: *copy /app/node_modules/dd-trace/packages/dd-trace/src/encode/index.js:144:15

 [C++]:
   ticks  total  nonlib   name

 [Summary]:
   ticks  total  nonlib   name
     34    1.3%    2.1%  JavaScript
      0    0.0%    0.0%  C++
    464   17.9%   28.3%  GC
    946   36.6%          Shared libraries
   1608   62.1%          Unaccounted

 [C++ entry points]:
   ticks    cpp   total   name

 [Bottom up (heavy) profile]:
  Note: percentage shows a share of a particular caller in the total
  amount of its parent calls.
  Callers occupying less than 1.0% are not shown.

   ticks parent  name
   1608   62.1%  UNKNOWN
    167   10.4%    LazyCompile: ~wrapSafe internal/modules/cjs/loader.js:1101:18
    167  100.0%      LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
    167  100.0%        LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
    167  100.0%          LazyCompile: ~Module.load internal/modules/cjs/loader.js:1037:33
    167  100.0%            LazyCompile: ~Module._load internal/modules/cjs/loader.js:877:24
     59    3.7%    LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
     53   89.8%      LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      4    7.5%        Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      3    5.7%        Eval: ~<anonymous> crypto.js:1:1
      3  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      3  100.0%            LazyCompile: ~compileForPublicLoader internal/bootstrap/loaders.js:212:25
      2    3.8%        LazyCompile: ~setupPrepareStackTrace internal/bootstrap/node.js:250:32
      2  100.0%          Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      2    3.8%        LazyCompile: ~setupBuffer internal/bootstrap/node.js:298:21
      2  100.0%          Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      2    3.8%        LazyCompile: ~initializeCJSLoader internal/bootstrap/pre_execution.js:399:29
      2  100.0%          LazyCompile: ~prepareMainThreadExecution internal/bootstrap/pre_execution.js:14:36
      2  100.0%            Eval: ~<anonymous> internal/main/run_main_module.js:1:1
      2    3.8%        Eval: ~<anonymous> tls.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      2    3.8%        Eval: ~<anonymous> stream.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      2    3.8%        Eval: ~<anonymous> internal/url.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      2    3.8%        Eval: ~<anonymous> internal/source_map/source_map_cache.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      2    3.8%        Eval: ~<anonymous> internal/modules/esm/loader.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      2    3.8%        Eval: ~<anonymous> internal/cluster/master.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      2    3.8%        Eval: ~<anonymous> http.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~compileForPublicLoader internal/bootstrap/loaders.js:212:25
      2    3.8%        Eval: ~<anonymous> events.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      2    3.8%        Eval: ~<anonymous> _http_agent.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.9%        LazyCompile: ~lazyLoadStreams fs.js:1915:25
      1  100.0%          LazyCompile: ~get ReadStream fs.js:2018:17
      1  100.0%            LazyCompile: ~getOwn internal/bootstrap/loaders.js:148:16
      1    1.9%        LazyCompile: ~initializeReport internal/bootstrap/pre_execution.js:165:26
      1  100.0%          LazyCompile: ~prepareMainThreadExecution internal/bootstrap/pre_execution.js:14:36
      1  100.0%            Eval: ~<anonymous> internal/main/run_main_module.js:1:1
      1    1.9%        LazyCompile: ~get fs.js:2073:8
      1  100.0%          LazyCompile: ~getOwn internal/bootstrap/loaders.js:148:16
      1  100.0%            LazyCompile: ~syncExports internal/bootstrap/loaders.js:251:14
      1    1.9%        LazyCompile: ~get dns.js:324:8
      1  100.0%          LazyCompile: ~getOwn internal/bootstrap/loaders.js:148:16
      1  100.0%            LazyCompile: ~syncExports internal/bootstrap/loaders.js:251:14
      1    1.9%        LazyCompile: ~createGlobalConsole internal/bootstrap/node.js:315:29
      1  100.0%          Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      1    1.9%        Eval: ~<anonymous> timers.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.9%        Eval: ~<anonymous> net.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.9%        Eval: ~<anonymous> internal/util/inspect.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.9%        Eval: ~<anonymous> internal/streams/lazy_transform.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.9%        Eval: ~<anonymous> internal/process/task_queues.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.9%        Eval: ~<anonymous> internal/modules/esm/module_map.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.9%        Eval: ~<anonymous> internal/modules/cjs/loader.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.9%        Eval: ~<anonymous> internal/modules/cjs/helpers.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.9%        Eval: ~<anonymous> internal/console/global.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.9%        Eval: ~<anonymous> internal/bootstrap/pre_execution.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.9%        Eval: ~<anonymous> fs.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.9%        Eval: ~<anonymous> dns.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~compileForPublicLoader internal/bootstrap/loaders.js:212:25
      1    1.9%        Eval: ~<anonymous> child_process.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.9%        Eval: ~<anonymous> buffer.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.9%        Eval: ~<anonymous> assert.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~compileForPublicLoader internal/bootstrap/loaders.js:212:25
      1    1.9%        Eval: ~<anonymous> _stream_readable.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.9%        Eval: ~<anonymous> _http_outgoing.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      6   10.2%      LazyCompile: ~compileForPublicLoader internal/bootstrap/loaders.js:212:25
      6  100.0%        LazyCompile: ~loadNativeModule internal/modules/cjs/helpers.js:21:26
      6  100.0%          LazyCompile: ~Module._load internal/modules/cjs/loader.js:877:24
      6  100.0%            LazyCompile: ~Module.require internal/modules/cjs/loader.js:1081:36
     52    3.2%    LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
     52  100.0%      LazyCompile: ~_activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:42:13
     52  100.0%        LazyCompile: ~activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:8:12
     52  100.0%          LazyCompile: ~bound /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:52:28
      3    5.8%            LazyCompile: ~emit events.js:263:44
      1    1.9%            LazyCompile: ~operationWithTrace /app/node_modules/dd-trace/packages/datadog-plugin-mongodb-core/src/index.js:7:40
      1    1.9%            LazyCompile: ~connectWithTrace /app/node_modules/dd-trace/packages/datadog-plugin-net/src/index.js:8:38
     26    1.6%    LazyCompile: ~readPackage internal/modules/cjs/loader.js:251:21
     18   69.2%      LazyCompile: ~readPackageExports internal/modules/cjs/loader.js:308:28
     18  100.0%        LazyCompile: ~applyExports internal/modules/cjs/loader.js:447:22
     16   88.9%          LazyCompile: ~resolveExports internal/modules/cjs/loader.js:504:24
     16  100.0%            LazyCompile: ~Module._findPath internal/modules/cjs/loader.js:613:28
      2   11.1%          LazyCompile: *Module._findPath internal/modules/cjs/loader.js:613:28
      2  100.0%            LazyCompile: ~Module._resolveFilename internal/modules/cjs/loader.js:964:35
      8   30.8%      LazyCompile: ~readPackageScope internal/modules/cjs/loader.js:285:26
      7   87.5%        LazyCompile: ~trySelf internal/modules/cjs/loader.js:402:17
      7  100.0%          LazyCompile: ~Module._resolveFilename internal/modules/cjs/loader.js:964:35
      5   71.4%            LazyCompile: ~Module._load internal/modules/cjs/loader.js:877:24
      2   28.6%            LazyCompile: ~Module.require /app/node_modules/require-in-the-middle/index.js:26:39
      1   12.5%        LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
      1  100.0%          LazyCompile: ~Module.load internal/modules/cjs/loader.js:1037:33
      1  100.0%            LazyCompile: ~Module._load internal/modules/cjs/loader.js:877:24
     23    1.4%    LazyCompile: ~stat internal/modules/cjs/loader.js:145:14
     16   69.6%      LazyCompile: ~Module._findPath internal/modules/cjs/loader.js:613:28
     16  100.0%        LazyCompile: ~Module._resolveFilename internal/modules/cjs/loader.js:964:35
      8   50.0%          LazyCompile: ~Module.require /app/node_modules/require-in-the-middle/index.js:26:39
      8  100.0%            LazyCompile: ~require internal/modules/cjs/helpers.js:72:31
      8   50.0%          LazyCompile: ~Module._load internal/modules/cjs/loader.js:877:24
      8  100.0%            LazyCompile: ~Module.require internal/modules/cjs/loader.js:1081:36
      6   26.1%      LazyCompile: ~tryFile internal/modules/cjs/loader.js:359:17
      6  100.0%        LazyCompile: ~tryExtensions internal/modules/cjs/loader.js:375:23
      3   50.0%          LazyCompile: ~tryPackage internal/modules/cjs/loader.js:313:20
      2   66.7%            LazyCompile: ~Module._findPath internal/modules/cjs/loader.js:613:28
      1   33.3%            LazyCompile: *Module._findPath internal/modules/cjs/loader.js:613:28
      3   50.0%          LazyCompile: ~Module._findPath internal/modules/cjs/loader.js:613:28
      3  100.0%            LazyCompile: ~Module._resolveFilename internal/modules/cjs/loader.js:964:35
      1    4.3%      LazyCompile: *Module._findPath internal/modules/cjs/loader.js:613:28
      1  100.0%        LazyCompile: ~Module._resolveFilename internal/modules/cjs/loader.js:964:35
      1  100.0%          LazyCompile: ~Module.require /app/node_modules/require-in-the-middle/index.js:26:39
      1  100.0%            LazyCompile: ~require internal/modules/cjs/helpers.js:72:31

    914   35.3%  /lib/ld-musl-x86_64.so.1
     13    1.4%    LazyCompile: ~exports.floatFormatter /app/node_modules/hdr-histogram-js/formatters.js:15:35
     13  100.0%      Eval: ~<anonymous> /app/node_modules/hdr-histogram-js/HistogramLogWriter.js:1:1
     13  100.0%        LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
     13  100.0%          LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
     13  100.0%            LazyCompile: ~Module.load internal/modules/cjs/loader.js:1037:33

     26    1.0%  /usr/lib/libstdc++.so.6.0.27
      1    3.8%    LazyCompile: ~writeU_Int32LE internal/buffer.js:681:24
      1  100.0%      LazyCompile: ~writeInt32LE internal/buffer.js:851:22
      1  100.0%        LazyCompile: ~toBin /app/node_modules/mongodb-core/lib/connection/msg.js:77:8
      1  100.0%          LazyCompile: ~serializeCommand /app/node_modules/mongodb-core/lib/connection/pool.js:770:26
      1  100.0%            LazyCompile: ~Pool.write /app/node_modules/mongodb-core/lib/connection/pool.js:815:32
      1    3.8%    LazyCompile: ~wrap /app/node_modules/dd-trace/packages/dd-trace/src/instrumenter.js:72:8
      1  100.0%      LazyCompile: ~patchClassicFunctions /app/node_modules/dd-trace/packages/datadog-plugin-fs/src/index.js:371:32
      1  100.0%        LazyCompile: ~patch /app/node_modules/dd-trace/packages/datadog-plugin-fs/src/index.js:478:9
      1  100.0%          LazyCompile: ~patch /app/node_modules/dd-trace/packages/dd-trace/src/instrumenter.js:168:9
      1  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/loader.js:97:22
      1    3.8%    LazyCompile: ~satisfies /app/node_modules/semver/semver.js:1183:19
      1  100.0%      LazyCompile: ~validate /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/validate.js:7:19
      1  100.0%        LazyCompile: ~init /app/node_modules/dd-trace/packages/dd-trace/src/proxy.js:26:8
      1  100.0%          Eval: ~<anonymous> /app/src/index.js:1:1
      1  100.0%            LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
      1    3.8%    LazyCompile: ~removeDotSegments /app/node_modules/uri-js/dist/es5/uri.all.js:975:27
      1  100.0%      LazyCompile: ~serialize /app/node_modules/uri-js/dist/es5/uri.all.js:1001:19
      1  100.0%        LazyCompile: ~_getFullPath /app/node_modules/ajv/lib/compile/resolve.js:214:22
      1  100.0%          LazyCompile: ~getFullPath /app/node_modules/ajv/lib/compile/resolve.js:207:21
      1  100.0%            LazyCompile: ~resolveIds /app/node_modules/ajv/lib/compile/resolve.js:232:20
      1    3.8%    LazyCompile: ~parseConnectionString /app/node_modules/mongodb-core/lib/uri_parser.js:399:31
      1  100.0%      LazyCompile: ~connect /app/node_modules/mongodb/lib/operations/mongo_client_ops.js:176:17
      1  100.0%        LazyCompile: ~connectOp /app/node_modules/mongodb/lib/operations/mongo_client_ops.js:280:19
      1  100.0%          LazyCompile: ~executeOperation /app/node_modules/mongodb/lib/utils.js:364:26
      1  100.0%            LazyCompile: ~MongoClient.connect /app/node_modules/mongodb/lib/mongo_client.js:161:41
      1    3.8%    LazyCompile: ~md5 /app/node_modules/md5/md5.js:8:18
      1  100.0%      LazyCompile: ~module.exports /app/node_modules/md5/md5.js:150:29
      1  100.0%        LazyCompile: ~deref /app/node_modules/json-schema-deref-sync/lib/index.js:281:16
      1  100.0%          Eval: ~<anonymous> /app/config/schema.js:1:1
      1  100.0%            LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
      1    3.8%    LazyCompile: ~is_http_iri /app/node_modules/valid-url/index.js:83:25
      1  100.0%      LazyCompile: ~is_web_iri /app/node_modules/valid-url/index.js:149:24
      1  100.0%        LazyCompile: ~getRefType /app/node_modules/json-schema-deref-sync/lib/utils.js:30:21
      1  100.0%          LazyCompile: ~<anonymous> /app/node_modules/json-schema-deref-sync/lib/index.js:159:51
      1  100.0%            LazyCompile: ~<anonymous> /app/node_modules/traverse/index.js:57:27
      1    3.8%    LazyCompile: ~getArrayPrefixes /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:39:27
      1  100.0%      Eval: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:1:1
      1  100.0%        LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
      1  100.0%          LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
      1  100.0%            LazyCompile: ~Module.load internal/modules/cjs/loader.js:1037:33
      1    3.8%    LazyCompile: ~exports.connect /app/node_modules/@shortlyster/mongalisa/dist/config.js:11:19
      1  100.0%      Eval: ~<anonymous> /app/config/mongo.js:1:1
      1  100.0%        LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
      1  100.0%          LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
      1  100.0%            LazyCompile: ~Module.load internal/modules/cjs/loader.js:1037:33
      1    3.8%    LazyCompile: ~executeUserEntryPoint internal/modules/run_main.js:64:31
      1  100.0%      Eval: ~<anonymous> internal/main/run_main_module.js:1:1
      1    3.8%    LazyCompile: ~captureCounters /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:230:26
      1  100.0%      LazyCompile: ~captureCommonMetrics /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:249:31
      1  100.0%        LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
      1    3.8%    LazyCompile: ~bytesToWords /app/node_modules/crypt/crypt.js:37:27
      1  100.0%      LazyCompile: ~md5 /app/node_modules/md5/md5.js:8:18
      1  100.0%        LazyCompile: ~module.exports /app/node_modules/md5/md5.js:150:29
      1  100.0%          LazyCompile: ~deref /app/node_modules/json-schema-deref-sync/lib/index.js:281:16
      1  100.0%            Eval: ~<anonymous> /app/config/schema.js:1:1
      1    3.8%    LazyCompile: ~basename path.js:1153:11
      1  100.0%      LazyCompile: ~findLongestRegisteredExtension internal/modules/cjs/loader.js:388:40
      1  100.0%        LazyCompile: ~Module.load internal/modules/cjs/loader.js:1037:33
      1  100.0%          LazyCompile: ~Module._load internal/modules/cjs/loader.js:877:24
      1  100.0%            LazyCompile: ~Module.require internal/modules/cjs/loader.js:1081:36
      1    3.8%    LazyCompile: ~arrayEach /app/node_modules/lodash/lodash.js:511:21
      1  100.0%      LazyCompile: ~mixin /app/node_modules/lodash/lodash.js:15688:19
      1  100.0%        Eval: ~runInContext /app/node_modules/lodash/lodash.js:1406:44
      1  100.0%          Eval: ~<anonymous> /app/node_modules/lodash/lodash.js:9:11
      1  100.0%            Eval: ~<anonymous> /app/node_modules/lodash/lodash.js:1:1
      1    3.8%    LazyCompile: ~_send _http_outgoing.js:297:49
      1  100.0%      LazyCompile: ~write_ _http_outgoing.js:653:16
      1  100.0%        LazyCompile: ~write _http_outgoing.js:635:49
      1  100.0%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/request.js:46:16
      1  100.0%            LazyCompile: ~request /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/request.js:9:18
      1    3.8%    LazyCompile: ~_addSchema /app/node_modules/ajv/lib/ajv.js:290:20
      1  100.0%      LazyCompile: ~addSchema /app/node_modules/ajv/lib/ajv.js:126:19
      1  100.0%        LazyCompile: ~addMetaSchema /app/node_modules/ajv/lib/ajv.js:150:23
      1  100.0%          LazyCompile: ~addDefaultMetaSchema /app/node_modules/ajv/lib/ajv.js:440:30
      1  100.0%            LazyCompile: ~Ajv /app/node_modules/ajv/lib/ajv.js:51:13
      1    3.8%    LazyCompile: ~Readable _stream_readable.js:181:18
      1  100.0%      LazyCompile: ~Duplex _stream_duplex.js:52:16
      1  100.0%        LazyCompile: ~Socket net.js:264:16
      1  100.0%          LazyCompile: ~WriteStream tty.js:84:21
      1  100.0%            LazyCompile: ~createWritableStdioStream internal/bootstrap/switches/is_main_thread.js:37:35
      1    3.8%    LazyCompile: ~<anonymous> /app/node_modules/mongodb-core/lib/connection/connection.js:421:18
      1  100.0%      LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
      1  100.0%        LazyCompile: ~_activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:42:13
      1  100.0%          LazyCompile: ~activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:8:12
      1  100.0%            LazyCompile: ~bound /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:52:28
      1    3.8%    LazyCompile: ~<anonymous> /app/node_modules/mongodb-core/lib/connection/connect.js:119:57
      1  100.0%      LazyCompile: ~messageHandler /app/node_modules/mongodb-core/lib/connection/connect.js:310:26
      1  100.0%        LazyCompile: ~emit events.js:263:44
      1  100.0%          LazyCompile: ~processMessage /app/node_modules/mongodb-core/lib/connection/connection.js:360:24
      1  100.0%            LazyCompile: ~<anonymous> /app/node_modules/mongodb-core/lib/connection/connection.js:421:18

kaievns commented 4 years ago

and here is another one, off the actual box in production:



 [Shared libraries]:
   ticks  total  nonlib   name
   1176   33.9%          /lib/ld-musl-x86_64.so.1
     19    0.5%          /usr/lib/libstdc++.so.6.0.27
      5    0.1%          [vdso]
      2    0.1%          /usr/local/bin/node

 [JavaScript]:
   ticks  total  nonlib   name
      7    0.2%    0.3%  LazyCompile: *resolve path.js:973:10
      5    0.1%    0.2%  RegExp: if\s*\([^)]+\)\s*\{\s*\}(?!\s*else)
      4    0.1%    0.2%  LazyCompile: *hidden internal/errors.js:282:25
      3    0.1%    0.1%  LazyCompile: *getStrPrefixes /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:5:25
      3    0.1%    0.1%  LazyCompile: *getMapPrefixes /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:56:25
      2    0.1%    0.1%  LazyCompile: *nextTick internal/process/task_queues.js:105:18
      2    0.1%    0.1%  LazyCompile: *getArrayPrefixes /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:39:27
      1    0.0%    0.0%  RegExp: if\s*\(([^)]+)\)\s*\{\s*\}\s*else(?!\s*if)
      1    0.0%    0.0%  RegExp: else\s*{\s*}
      1    0.0%    0.0%  RegExp: data1[^0-9]
      1    0.0%    0.0%  RegExp: ^\/|\\
      1    0.0%    0.0%  RegExp: ^[a-z$_][a-z$_0-9]*$
      1    0.0%    0.0%  RegExp: ^((?:@[^/\\%]+\/)?[^./\\%][^/\\%]*)(\/.*)?$
      1    0.0%    0.0%  RegExp: (?:(?:%[EFef][0-9A-Fa-f]%[0-9A-Fa-f][0-9A-Fa-f]%[0-9A-Fa-f][0-9A-Fa-f])|(?:%[89A-Fa-f][0-9A-Fa-f]%[0-9A-Fa-f][0-9A-Fa-f])|(?:%[0-9A-Fa-f][0-9A-Fa-f]))
      1    0.0%    0.0%  LazyCompile: *removeListenerWithTrace /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:170:43
      1    0.0%    0.0%  LazyCompile: *pushAsyncContext internal/async_hooks.js:459:26
      1    0.0%    0.0%  LazyCompile: *normalizeString path.js:52:25
      1    0.0%    0.0%  LazyCompile: *allocUnsafe buffer.js:383:42
      1    0.0%    0.0%  LazyCompile: *addListenerWithTrace /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:144:40

 [C++]:
   ticks  total  nonlib   name

 [Summary]:
   ticks  total  nonlib   name
     38    1.1%    1.7%  JavaScript
      0    0.0%    0.0%  C++
    585   16.9%   25.9%  GC
   1202   34.7%          Shared libraries
   2225   64.2%          Unaccounted

 [C++ entry points]:
   ticks    cpp   total   name

 [Bottom up (heavy) profile]:
  Note: percentage shows a share of a particular caller in the total
  amount of its parent calls.
  Callers occupying less than 1.0% are not shown.

   ticks parent  name
   2225   64.2%  UNKNOWN
    158    7.1%    LazyCompile: ~wrapSafe internal/modules/cjs/loader.js:1101:18
    158  100.0%      LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
    158  100.0%        LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
    158  100.0%          LazyCompile: ~Module.load internal/modules/cjs/loader.js:1037:33
    158  100.0%            LazyCompile: ~Module._load internal/modules/cjs/loader.js:877:24
     64    2.9%    LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
     56   87.5%      LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      4    7.1%        Eval: ~<anonymous> crypto.js:1:1
      4  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      4  100.0%            LazyCompile: ~compileForPublicLoader internal/bootstrap/loaders.js:212:25
      3    5.4%        Eval: ~<anonymous> stream.js:1:1
      3  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      3  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      3    5.4%        Eval: ~<anonymous> internal/source_map/source_map_cache.js:1:1
      3  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      3  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      3    5.4%        Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      3    5.4%        Eval: ~<anonymous> fs.js:1:1
      3  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      3  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      2    3.6%        LazyCompile: ~setupPrepareStackTrace internal/bootstrap/node.js:250:32
      2  100.0%          Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      2    3.6%        LazyCompile: ~initializeCJSLoader internal/bootstrap/pre_execution.js:399:29
      2  100.0%          LazyCompile: ~prepareMainThreadExecution internal/bootstrap/pre_execution.js:14:36
      2  100.0%            Eval: ~<anonymous> internal/main/run_main_module.js:1:1
      2    3.6%        Eval: ~<anonymous> tls.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      2    3.6%        Eval: ~<anonymous> internal/url.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      2    3.6%        Eval: ~<anonymous> internal/process/task_queues.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      2    3.6%        Eval: ~<anonymous> internal/modules/esm/loader.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      2    3.6%        Eval: ~<anonymous> internal/cluster/master.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      2    3.6%        Eval: ~<anonymous> http.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~compileForPublicLoader internal/bootstrap/loaders.js:212:25
      2    3.6%        Eval: ~<anonymous> events.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      2    3.6%        Eval: ~<anonymous> buffer.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      2    3.6%        Eval: ~<anonymous> _http_agent.js:1:1
      2  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.8%        LazyCompile: ~setupProcessObject internal/bootstrap/node.js:269:28
      1  100.0%          Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      1    1.8%        LazyCompile: ~setupBuffer internal/bootstrap/node.js:298:21
      1  100.0%          Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      1    1.8%        LazyCompile: ~listenInCluster net.js:1351:25
      1  100.0%          LazyCompile: ~Server.listen net.js:1393:35
      1  100.0%            Eval: ~<anonymous> /app/bin/server:1:1
      1    1.8%        LazyCompile: ~initializeReport internal/bootstrap/pre_execution.js:165:26
      1  100.0%          LazyCompile: ~prepareMainThreadExecution internal/bootstrap/pre_execution.js:14:36
      1  100.0%            Eval: ~<anonymous> internal/main/run_main_module.js:1:1
      1    1.8%        LazyCompile: ~get fs.js:2073:8
      1  100.0%          LazyCompile: ~getOwn internal/bootstrap/loaders.js:148:16
      1  100.0%            LazyCompile: ~syncExports internal/bootstrap/loaders.js:251:14
      1    1.8%        LazyCompile: ~get dns.js:324:8
      1  100.0%          LazyCompile: ~getOwn internal/bootstrap/loaders.js:148:16
      1  100.0%            LazyCompile: ~syncExports internal/bootstrap/loaders.js:251:14
      1    1.8%        LazyCompile: ~createGlobalConsole internal/bootstrap/node.js:315:29      1  100.0%          Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      1    1.8%        Eval: ~<anonymous> internal/timers.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.8%        Eval: ~<anonymous> internal/streams/lazy_transform.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.8%        Eval: ~<anonymous> internal/modules/cjs/helpers.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.8%        Eval: ~<anonymous> internal/main/run_main_module.js:1:1
      1    1.8%        Eval: ~<anonymous> internal/fs/promises.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.8%        Eval: ~<anonymous> internal/console/global.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.8%        Eval: ~<anonymous> internal/bootstrap/switches/is_main_thread.js:1:1
      1    1.8%        Eval: ~<anonymous> https.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~compileForPublicLoader internal/bootstrap/loaders.js:212:25
      1    1.8%        Eval: ~<anonymous> child_process.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.8%        Eval: ~<anonymous> _http_common.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.8%        Eval: ~<anonymous> _http_client.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      8   12.5%      LazyCompile: ~compileForPublicLoader internal/bootstrap/loaders.js:212:25
      8  100.0%        LazyCompile: ~loadNativeModule internal/modules/cjs/helpers.js:21:26
      8  100.0%          LazyCompile: ~Module._load internal/modules/cjs/loader.js:877:24
      8  100.0%            LazyCompile: ~Module.require internal/modules/cjs/loader.js:1081:36
     53    2.4%    LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
     53  100.0%      LazyCompile: ~_activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:42:13
     53  100.0%        LazyCompile: ~activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:8:12
     53  100.0%          LazyCompile: ~bound /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:52:28
     33   62.3%            LazyCompile: ~emit events.js:263:44
      9   17.0%            LazyCompile: ~onceWrapper events.js:416:21
      8   15.1%            LazyCompile: *emit events.js:263:44
      2    3.8%            LazyCompile: ~connectWithTrace /app/node_modules/dd-trace/packages/datadog-plugin-net/src/index.js:8:38
      1    1.9%            LazyCompile: ~operationWithTrace /app/node_modules/dd-trace/packages/datadog-plugin-mongodb-core/src/index.js:7:40
     47    2.1%    LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36     44   93.6%      LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
      3    6.4%      LazyCompile: ~afterDns dgram.js:626:20
      3  100.0%        LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
     37    1.7%    LazyCompile: ~request http.js:46:17
     37  100.0%      LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
     37  100.0%        LazyCompile: ~_activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:42:13
     37  100.0%          LazyCompile: ~activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:8:12
     37  100.0%            LazyCompile: ~bound /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:52:28
     30    1.3%    LazyCompile: ~readPackage internal/modules/cjs/loader.js:251:21
     17   56.7%      LazyCompile: ~readPackageExports internal/modules/cjs/loader.js:308:28
     17  100.0%        LazyCompile: ~applyExports internal/modules/cjs/loader.js:447:22
     14   82.4%          LazyCompile: ~resolveExports internal/modules/cjs/loader.js:504:24
     14  100.0%            LazyCompile: ~Module._findPath internal/modules/cjs/loader.js:613:28
      3   17.6%          LazyCompile: *Module._findPath internal/modules/cjs/loader.js:613:28
      3  100.0%            LazyCompile: ~Module._resolveFilename internal/modules/cjs/loader.js:964:35
     13   43.3%      LazyCompile: ~readPackageScope internal/modules/cjs/loader.js:285:26
      8   61.5%        LazyCompile: ~trySelf internal/modules/cjs/loader.js:402:17
      8  100.0%          LazyCompile: ~Module._resolveFilename internal/modules/cjs/loader.js:964:35
      4   50.0%            LazyCompile: ~Module.require /app/node_modules/require-in-the-middle/index.js:26:39
      4   50.0%            LazyCompile: ~Module._load internal/modules/cjs/loader.js:877:24
      5   38.5%        LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
      5  100.0%          LazyCompile: ~Module.load internal/modules/cjs/loader.js:1037:33
      5  100.0%            LazyCompile: ~Module._load internal/modules/cjs/loader.js:877:24
     23    1.0%    LazyCompile: ~deserializeObject /app/node_modules/bson/lib/bson/parser/deserializer.js:43:33
     13   56.5%      LazyCompile: ~deserialize /app/node_modules/bson/lib/bson/parser/deserializer.js:19:27
     13  100.0%        LazyCompile: ~BSON.deserialize /app/node_modules/bson/lib/bson/bson.js:134:38
     12   92.3%          LazyCompile: ~parse /app/node_modules/mongodb-core/lib/connection/msg.js:168:8
     12  100.0%            LazyCompile: ~<anonymous> /app/node_modules/mongodb-core/lib/connection/pool.js:354:18
      1    7.7%          LazyCompile: ~Response.parse /app/node_modules/mongodb-core/lib/connection/commands.js:438:36
      1  100.0%            LazyCompile: ~messageHandler /app/node_modules/mongodb-core/lib/connection/connect.js:310:26
     10   43.5%      LazyCompile: ~deserializeObject /app/node_modules/bson/lib/bson/parser/deserializer.js:43:33
      5   50.0%        LazyCompile: ~deserializeObject /app/node_modules/bson/lib/bson/parser/deserializer.js:43:33
      5  100.0%          LazyCompile: ~deserialize /app/node_modules/bson/lib/bson/parser/deserializer.js:19:27
      5  100.0%            LazyCompile: ~BSON.deserialize /app/node_modules/bson/lib/bson/bson.js:134:38
      5   50.0%        LazyCompile: ~deserialize /app/node_modules/bson/lib/bson/parser/deserializer.js:19:27
      5  100.0%          LazyCompile: ~BSON.deserialize /app/node_modules/bson/lib/bson/bson.js:134:38
      4   80.0%            LazyCompile: ~parse /app/node_modules/mongodb-core/lib/connection/msg.js:168:8
      1   20.0%            LazyCompile: ~Response.parse /app/node_modules/mongodb-core/lib/connection/commands.js:438:36

   1176   33.9%  /lib/ld-musl-x86_64.so.1
     13    1.1%    LazyCompile: ~exports.floatFormatter /app/node_modules/hdr-histogram-js/formatters.js:15:35
     13  100.0%      Eval: ~<anonymous> /app/node_modules/hdr-histogram-js/HistogramLogWriter.js:1:1
     13  100.0%        LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
     13  100.0%          LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
     13  100.0%            LazyCompile: ~Module.load internal/modules/cjs/loader.js:1037:33```

kaievns commented 4 years ago

what else can i try here?

rochdev commented 4 years ago

Both profiles look very similar. What was enabled in each one? Ideally there would be one with the http plugin and one without it, in the same environment.

runtime mentrics don't show much i order to debug the problem, it's just a total CPU/memory usage on the box

There are actually a lot more metrics than that. We also track things like event loop stats, GC stats, the average number of spans in memory, asynchronous resources, etc. It's important to check if there are big differences for any of those.

setting scope: 'noop' didnt do anything setting trackAsyncScope: false drops idle usage from 100mc to ~50mc (5x above the baseline)

That's an odd result, since setting the scope to noop would also result in trackAsyncScope being disabled, so it should have at a minimum the same positive impact. How did you set the option?

kaievns commented 4 years ago

oh, sorry, i meant scope: 'noop' had the same result as trackAsyncScore: false

the profiles above both have all the plugins enabled, i'll try without the plugins and will post them in here

kaievns commented 4 years ago

the weird thing is that I don't see anything drastic on the inside of the node profile, most of it looks like JS compilation time. but the kubes register a 5x increased CPU consumption by the pod. could there be anything else going on in the node/agent interop?

rochdev commented 4 years ago

It depends somewhat on the actual usage. For example, for a completely idle service, the tracer will be waking it up constantly, so it is expected that there is a large increase. For a service with actual usage, 10x should definitely not happen since that would mean going from 10% to 100%. I know that k8s sometime is a bit too smart in managing the CPU which can skew numbers, but I've not seen a change this bad juste because of that.

kaievns commented 4 years ago

no, it's an actually active service, the liveness check hits it every 2 seconds, so it never sleeps.

see those spikes in the graph above? those are real usage records on all services from our automatic QA cycle run on the application. the amount of CPU consumed on idle service was close to the real usage consumption, and after disabling the trackAsyncScope it is half of that.

and it's not the tracing itself, none of those exist or visible when http related plugins are disabled

kaievns commented 4 years ago

ohi, was wondering if there any further thoughts on this? any more information i can pull up for you to help mitigating this problem? here is the node runtime metrics data in the past few hours, the left side is wits plugins: false and the right one is with all plugins enabled. The spike in the middle is the actual usage from automated QA run.

rochdev commented 4 years ago

I'm afraid we'll need a reproduction snippet at this point since there should be pretty much nothing happening in the tracer while idling other than runtime metrics being captured which is very low overhead. You mentioned this is happening while idle and/or with just a health check, so I assume it should be possible to simply remove all logic from the application and send the result as the snippet. Please note that if the snippet contains anything sensitive at all you should go through our support team and not post anything here.

kaievns commented 4 years ago

so, i've reduced the entire application to a pretty much empty express app that has stubs for responding to liveness checks. no codebase, no deps, no nothing. and i still see exactly the same picture. i'm a bit at loss here. also did two new profiles, this one is with plugins enabled.



 [Shared libraries]:
   ticks  total  nonlib   name
  14725   50.2%          /lib/ld-musl-x86_64.so.1
  13571   46.3%          /usr/local/bin/node
    110    0.4%          /usr/lib/libstdc++.so.6.0.27
     29    0.1%          [vdso]

 [JavaScript]:
   ticks  total  nonlib   name
     52    0.2%    6.0%  LazyCompile: *addListenerWithTrace /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:144:40
     36    0.1%    4.1%  LazyCompile: *_destroy /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:130:12
     26    0.1%    3.0%  LazyCompile: *wrapCallHandle /app/node_modules/dd-trace/packages/datadog-plugin-router/src/index.js:44:31
     26    0.1%    3.0%  LazyCompile: *emitInitNative internal/async_hooks.js:139:24
     23    0.1%    2.6%  LazyCompile: *nextTick internal/process/task_queues.js:105:18
     23    0.1%    2.6%  LazyCompile: *emitHook internal/async_hooks.js:170:18
     18    0.1%    2.1%  LazyCompile: *writeMap /app/node_modules/dd-trace/packages/dd-trace/src/encode/index.js:153:19
     14    0.0%    1.6%  LazyCompile: *writeInt64 /app/node_modules/dd-trace/packages/dd-trace/src/encode/util.js:31:21
     14    0.0%    1.6%  LazyCompile: *writeDoubleBackwards internal/buffer.js:905:30
     14    0.0%    1.6%  LazyCompile: *_storeHeader _http_outgoing.js:352:22
     13    0.0%    1.5%  LazyCompile: *emitAfterScript internal/async_hooks.js:427:25
     13    0.0%    1.5%  LazyCompile: *emit events.js:263:44
     13    0.0%    1.5%  LazyCompile: *_before /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:121:11
     11    0.0%    1.3%  LazyCompile: *formatSpan /app/node_modules/dd-trace/packages/dd-trace/src/format.js:31:21
     10    0.0%    1.1%  LazyCompile: *readableAddChunk _stream_readable.js:225:26
     10    0.0%    1.1%  LazyCompile: *hidden internal/errors.js:282:25
     10    0.0%    1.1%  LazyCompile: *count /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:116:11
     10    0.0%    1.1%  LazyCompile: *_startSpan /app/node_modules/dd-trace/packages/dd-trace/src/opentracing/tracer.js:58:14
      9    0.0%    1.0%  LazyCompile: *DatadogSpanContext /app/node_modules/dd-trace/packages/dd-trace/src/opentracing/span_context.js:6:15
      8    0.0%    0.9%  RegExp: (\[[^[\]]*])
      8    0.0%    0.9%  LazyCompile: *write /app/node_modules/dd-trace/packages/dd-trace/src/encode/index.js:133:16
      8    0.0%    0.9%  LazyCompile: *module.exports /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:27:27
      7    0.0%    0.8%  LazyCompile: *once events.js:434:44
      7    0.0%    0.8%  LazyCompile: *listOnTimeout internal/timers.js:497:25
      7    0.0%    0.8%  LazyCompile: *_bindEmitter /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:69:16      7    0.0%    0.8%  LazyCompile: *_after /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:126:10
      7    0.0%    0.8%  LazyCompile: *<anonymous> internal/util/debuglog.js:63:18
      6    0.0%    0.7%  LazyCompile: *matchKnownFields _http_incoming.js:158:26
      6    0.0%    0.7%  LazyCompile: *activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:8:12
      6    0.0%    0.7%  LazyCompile: *_activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:45:13
      6    0.0%    0.7%  LazyCompile: *Readable.removeListener _stream_readable.js:880:45
      5    0.0%    0.6%  RegExp: [^a-z0-9_:./-]
      5    0.0%    0.6%  LazyCompile: *resume _stream_readable.js:951:16
      5    0.0%    0.6%  LazyCompile: *processPromiseRejections internal/process/promises.js:171:34
      5    0.0%    0.6%  LazyCompile: *add /app/node_modules/dd-trace/packages/dd-trace/src/tagger.js:5:14
      5    0.0%    0.6%  LazyCompile: *active /app/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:174:10
      5    0.0%    0.6%  LazyCompile: *<anonymous> /app/node_modules/express/lib/router/index.js:629:19
      4    0.0%    0.5%  LazyCompile: *writeHead _http_server.js:244:19
      4    0.0%    0.5%  LazyCompile: *shift internal/fixed_queue.js:108:8
      4    0.0%    0.5%  LazyCompile: *hasHooks internal/async_hooks.js:384:18
      4    0.0%    0.5%  LazyCompile: *get net.js:1679:6
      4    0.0%    0.5%  LazyCompile: *endReadable _stream_readable.js:1207:21
      4    0.0%    0.5%  LazyCompile: *emitBeforeScript internal/async_hooks.js:419:26
      4    0.0%    0.5%  LazyCompile: *arrayClone events.js:605:20
      3    0.0%    0.3%  RegExp: ^[\^_`a-zA-Z\-0-9!#$%&'*+.|~]+$
      3    0.0%    0.3%  LazyCompile: *shift internal/fixed_queue.js:80:8
      3    0.0%    0.3%  LazyCompile: *resolve path.js:973:10
      3    0.0%    0.3%  LazyCompile: *insert internal/timers.js:340:16
      3    0.0%    0.3%  LazyCompile: *howMuchToRead _stream_readable.js:366:23
      3    0.0%    0.3%  LazyCompile: *get internal/bootstrap/pre_execution.js:304:8
      3    0.0%    0.3%  LazyCompile: *get _stream_writable.js:698:8
      3    0.0%    0.3%  LazyCompile: *emitReadable_ _stream_readable.js:558:23
      3    0.0%    0.3%  LazyCompile: *addTag /app/node_modules/dd-trace/packages/dd-trace/src/format.js:122:17
      3    0.0%    0.3%  LazyCompile: *Writable.write _stream_writable.js:258:36
      3    0.0%    0.3%  LazyCompile: *Readable.resume _stream_readable.js:937:37
      3    0.0%    0.3%  LazyCompile: *<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:224:26
      2    0.0%    0.2%  RegExp: ^\/_health\/alive\/?$ {1}
      2    0.0%    0.2%  RegExp: ^\/_health\/alive\/?$
      2    0.0%    0.2%  RegExp: [^\u0021-\u00ff]
      2    0.0%    0.2%  RegExp: .*
      2    0.0%    0.2%  LazyCompile: *toNumberString /app/node_modules/dd-trace/packages/dd-trace/src/id.js:97:25
      2    0.0%    0.2%  LazyCompile: *slice buffer.js:1106:40
      2    0.0%    0.2%  LazyCompile: *removeListener events.js:451:28
      2    0.0%    0.2%  LazyCompile: *remove internal/linkedlist.js:15:16
      2    0.0%    0.2%  LazyCompile: *pushAsyncContext internal/async_hooks.js:459:26
      2    0.0%    0.2%  LazyCompile: *onwrite _stream_writable.js:394:17
      2    0.0%    0.2%  LazyCompile: *normalizeString path.js:52:25
      2    0.0%    0.2%  LazyCompile: *getStrPrefixes /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:5:25
      2    0.0%    0.2%  LazyCompile: *getMapPrefixes /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:56:25
      2    0.0%    0.2%  LazyCompile: *finishMaybe _stream_writable.js:623:21
      2    0.0%    0.2%  LazyCompile: *finish /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:93:19
      2    0.0%    0.2%  LazyCompile: *destroy internal/streams/destroy.js:5:17
      2    0.0%    0.2%  LazyCompile: *connectionListenerInternal _http_server.js:407:36
      2    0.0%    0.2%  LazyCompile: *checkInvalidHeaderChar _http_common.js:221:32
      2    0.0%    0.2%  LazyCompile: *allocUnsafe buffer.js:383:42
      2    0.0%    0.2%  LazyCompile: *_bindFn /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:46:11
      2    0.0%    0.2%  LazyCompile: *_addTags /app/node_modules/dd-trace/packages/dd-trace/src/opentracing/span.js:102:12
      2    0.0%    0.2%  LazyCompile: *_addHeaderLine _http_incoming.js:264:24
      2    0.0%    0.2%  LazyCompile: *Readable.read _stream_readable.js:383:35
      2    0.0%    0.2%  LazyCompile: *Readable.on _stream_readable.js:850:33
      2    0.0%    0.2%  LazyCompile: *<anonymous> _http_outgoing.js:521:45
      1    0.0%    0.1%  RegExp: ^\/_health\/ready\/?$
      1    0.0%    0.1%  RegExp: ^((?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])[.]){3}(?:[0-9]|[1-9][0-9]|1[0-9][0-9]|2[0-4][0-9]|25[0-5])$
      1    0.0%    0.1%  RegExp: [?#]
      1    0.0%    0.1%  RegExp: (\s*)(?:\^)\s+
      1    0.0%    0.1%  LazyCompile: *writeUInt8 internal/buffer.js:738:20
      1    0.0%    0.1%  LazyCompile: *writeUInt32BE /app/node_modules/dd-trace/packages/dd-trace/src/id.js:149:24
      1    0.0%    0.1%  LazyCompile: *wrapMethod /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:201:21
      1    0.0%    0.1%  LazyCompile: *toBuffer /app/node_modules/dd-trace/packages/dd-trace/src/id.js:33:12
      1    0.0%    0.1%  LazyCompile: *setStreamTimeout internal/stream_base_commons.js:234:26
      1    0.0%    0.1%  LazyCompile: *removeListenerWithTrace /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:170:43
      1    0.0%    0.1%  LazyCompile: *process_params /app/node_modules/express/lib/router/index.js:327:47
      1    0.0%    0.1%  LazyCompile: *onceWrapper events.js:416:21
      1    0.0%    0.1%  LazyCompile: *needFinish _stream_writable.js:588:20
      1    0.0%    0.1%  LazyCompile: *match /app/node_modules/express/lib/router/layer.js:110:39
      1    0.0%    0.1%  LazyCompile: *getNanoSeconds /app/node_modules/performance-now/lib/performance-now.js:14:30
      1    0.0%    0.1%  LazyCompile: *getHighWaterMark internal/streams/state.js:19:26
      1    0.0%    0.1%  LazyCompile: *get _stream_duplex.js:90:8
      1    0.0%    0.1%  LazyCompile: *finish /app/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:125:10
      1    0.0%    0.1%  LazyCompile: *fastparse /app/node_modules/parseurl/index.js:95:20
      1    0.0%    0.1%  LazyCompile: *endReadableNT _stream_readable.js:1217:23
      1    0.0%    0.1%  LazyCompile: *emitDestroyScript internal/async_hooks.js:435:27
      1    0.0%    0.1%  LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      1    0.0%    0.1%  LazyCompile: *callback _stream_writable.js:499:44
      1    0.0%    0.1%  LazyCompile: *byteLength buffer.js:721:20
      1    0.0%    0.1%  LazyCompile: *bound /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:52:28
      1    0.0%    0.1%  LazyCompile: *applyFilter /app/node_modules/dd-trace/packages/dd-trace/src/plugins/util/urlfilter.js:22:26
      1    0.0%    0.1%  LazyCompile: *_unrefTimer net.js:390:52
      1    0.0%    0.1%  LazyCompile: *_exit /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:64:9
      1    0.0%    0.1%  LazyCompile: *Span.addTags /app/node_modules/opentracing/lib/span.js:105:39
      1    0.0%    0.1%  LazyCompile: *Socket.end net.js:587:32
      1    0.0%    0.1%  LazyCompile: *Socket._read net.js:575:34
      1    0.0%    0.1%  LazyCompile: *EventEmitter events.js:64:22
      1    0.0%    0.1%  LazyCompile: *<anonymous> _http_outgoing.js:515:44
      1    0.0%    0.1%  LazyCompile: *<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43

 [C++]:
   ticks  total  nonlib   name

 [Summary]:
   ticks  total  nonlib   name
    606    2.1%   69.7%  JavaScript
      0    0.0%    0.0%  C++
   4741   16.2%  544.9%  GC
  28435   97.0%          Shared libraries
    264    0.9%          Unaccounted

 [C++ entry points]:
   ticks    cpp   total   name

 [Bottom up (heavy) profile]:
  Note: percentage shows a share of a particular caller in the total
  amount of its parent calls.
  Callers occupying less than 1.0% are not shown.

   ticks parent  name
  14725   50.2%  /lib/ld-musl-x86_64.so.1
    694    4.7%    /usr/local/bin/node
    120   17.3%      /usr/local/bin/node
     28   23.3%        LazyCompile: ~FastBuffer internal/buffer.js:945:1
     28  100.0%          LazyCompile: ~createUnsafeBuffer buffer.js:147:28
     28  100.0%            LazyCompile: *allocUnsafe buffer.js:383:42
     18   15.0%        LazyCompile: ~captureNativeMetrics /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:258:31
     18  100.0%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
     15   83.3%            LazyCompile: *listOnTimeout internal/timers.js:497:25
      3   16.7%            LazyCompile: ~listOnTimeout internal/timers.js:497:25
      9    7.5%        LazyCompile: ~captureCounters /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:230:26
      9  100.0%          LazyCompile: ~captureCommonMetrics /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:249:31
      9  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
      6    5.0%        LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:231:33
      6  100.0%          /usr/local/bin/node
      6  100.0%            LazyCompile: ~captureCounters /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:230:26
      6    5.0%        LazyCompile: *getMapPrefixes /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:56:25
      6  100.0%          LazyCompile: ~load /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/loader.js:32:8
      6  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/instrumenter.js:140:18
      4    3.3%        LazyCompile: ~checkInvalidHeaderChar _http_common.js:221:32
      4  100.0%          LazyCompile: ~<anonymous> _http_outgoing.js:521:45
      4  100.0%            LazyCompile: *hidden internal/errors.js:282:25
      4    3.3%        LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:223:31
      4  100.0%          /usr/local/bin/node
      4  100.0%            LazyCompile: ~captureGauges /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:222:24
      3    2.5%        LazyCompile: ~captureGauges /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:222:24
      3  100.0%          LazyCompile: ~captureCommonMetrics /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:249:31
      3  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
      3    2.5%        LazyCompile: ~_encode /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:100:11
      3  100.0%          LazyCompile: ~append /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:23:10
      2   66.7%            LazyCompile: ~export /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/index.js:18:10
      1   33.3%            LazyCompile: ~Span.finish /app/node_modules/opentracing/lib/span.js:159:38
      3    2.5%        LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:39:24
      3  100.0%          LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
      2    1.7%        LazyCompile: ~readPackage internal/modules/cjs/loader.js:251:21
      2  100.0%          LazyCompile: ~readPackageScope internal/modules/cjs/loader.js:285:26
      2  100.0%            LazyCompile: ~trySelf internal/modules/cjs/loader.js:402:17
      2    1.7%        LazyCompile: ~encodeUrl /app/node_modules/encodeurl/index.js:56:20
      2  100.0%          LazyCompile: ~<anonymous> /app/node_modules/finalhandler/index.js:86:19
      2  100.0%            LazyCompile: ~<anonymous> /app/node_modules/express/lib/router/index.js:629:19
      2    1.7%        LazyCompile: ~count /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:116:11
      1   50.0%          LazyCompile: ~increment /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:139:15
      1  100.0%            LazyCompile: ~_init /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:101:9
      1   50.0%          LazyCompile: ~decrement /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:143:15
      1  100.0%            LazyCompile: ~_destroy /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:130:12
      2    1.7%        LazyCompile: ~captureCommonMetrics /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:249:31
      2  100.0%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
      1   50.0%            LazyCompile: ~listOnTimeout internal/timers.js:497:25
      1   50.0%            LazyCompile: *listOnTimeout internal/timers.js:497:25
      2    1.7%        LazyCompile: ~_request /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:39:12
      2  100.0%          LazyCompile: ~flush /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:29:9
      2  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/index.js:13:39
      2    1.7%        LazyCompile: ~_getModules /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/loader.js:38:15
      2  100.0%          LazyCompile: ~load /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/loader.js:32:8
      2  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/instrumenter.js:140:18
      2    1.7%        LazyCompile: *<anonymous> _http_outgoing.js:521:45
      2  100.0%          LazyCompile: *hidden internal/errors.js:282:25
      2  100.0%            LazyCompile: ~setHeader _http_outgoing.js:531:57
     33    4.8%      LazyCompile: ~captureCommonMetrics /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:249:31
     32   97.0%        LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
     26   81.3%          LazyCompile: *listOnTimeout internal/timers.js:497:25
     16   61.5%            LazyCompile: ~processTimers internal/timers.js:477:25
     10   38.5%            LazyCompile: *processTimers internal/timers.js:477:25
      6   18.8%          LazyCompile: ~listOnTimeout internal/timers.js:497:25
      6  100.0%            LazyCompile: ~processTimers internal/timers.js:477:25
      1    3.0%        LazyCompile: ~getResourceName /app/node_modules/finalhandler/index.js:220:26
      1  100.0%          LazyCompile: ~listOnTimeout internal/timers.js:497:25
      1  100.0%            LazyCompile: ~processTimers internal/timers.js:477:25
     32    4.6%      LazyCompile: *emitInitNative internal/async_hooks.js:139:24
     11   34.4%        /usr/local/bin/node
      4   36.4%          LazyCompile: ~connectionListenerInternal _http_server.js:407:36
      4  100.0%            LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      3   27.3%          LazyCompile: ~internalConnect net.js:863:25
      2   66.7%            LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      1   33.3%            LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      2   18.2%          LazyCompile: ~tickOnSocket _http_client.js:728:22
      2  100.0%            LazyCompile: ~onSocketNT _http_client.js:794:20
      2   18.2%          LazyCompile: ~Socket._final net.js:400:35
      2  100.0%            LazyCompile: ~callFinal _stream_writable.js:597:19
      9   28.1%        LazyCompile: *endReadable _stream_readable.js:1207:21
      8   88.9%          LazyCompile: ~Readable.read _stream_readable.js:383:35
      3   37.5%            LazyCompile: ~flow _stream_readable.js:982:14
      2   25.0%            LazyCompile: *emitReadable_ _stream_readable.js:558:23
      1   12.5%            LazyCompile: ~resume_ _stream_readable.js:958:17
      1   12.5%            LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
      1   12.5%            LazyCompile: *childOf /app/node_modules/opentracing/lib/functions.js:13:17
      1   11.1%          LazyCompile: *Readable.read _stream_readable.js:383:35
      1  100.0%            LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
      1    3.1%        LazyCompile: ~emitInitScript internal/async_hooks.js:405:24
      1  100.0%          LazyCompile: ~initAsyncResource internal/timers.js:148:27
      1  100.0%            LazyCompile: ~Timeout internal/timers.js:158:17
      1    3.1%        LazyCompile: *setStreamTimeout internal/stream_base_commons.js:234:26
      1  100.0%          LazyCompile: ~<anonymous> _http_client.js:856:34
      1  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
     27    3.9%      LazyCompile: *_destroy /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:130:12     27  100.0%        LazyCompile: *emitHook internal/async_hooks.js:170:18
     26    3.7%      LazyCompile: ~encode /app/node_modules/dd-trace/packages/dd-trace/src/encode/index.js:60:17
     26  100.0%        LazyCompile: ~_encode /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:100:11
     26  100.0%          LazyCompile: ~append /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:23:10
     15   57.7%            LazyCompile: ~export /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/index.js:18:10
     11   42.3%            LazyCompile: ~Span.finish /app/node_modules/opentracing/lib/span.js:159:38
     19    2.7%      LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
     14   73.7%        LazyCompile: *listOnTimeout internal/timers.js:497:25
      8   57.1%          LazyCompile: *processTimers internal/timers.js:477:25
      6   42.9%          LazyCompile: ~processTimers internal/timers.js:477:25
      5   26.3%        LazyCompile: ~listOnTimeout internal/timers.js:497:25
      5  100.0%          LazyCompile: ~processTimers internal/timers.js:477:25
     15    2.2%      LazyCompile: ~ReadableState _stream_readable.js:87:23
     15  100.0%        LazyCompile: ~Readable _stream_readable.js:181:18
     13   86.7%          LazyCompile: ~Duplex _stream_duplex.js:52:16
     13  100.0%            LazyCompile: ~Socket net.js:264:16
      2   13.3%          LazyCompile: ~IncomingMessage _http_incoming.js:42:25
      2  100.0%            LazyCompile: ~parserOnHeadersComplete _http_common.js:72:33
     13    1.9%      LazyCompile: *_storeHeader _http_outgoing.js:352:22
      8   61.5%        LazyCompile: *writeHead _http_server.js:244:19
      8  100.0%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:290:19
      8  100.0%            LazyCompile: ~_implicitHeader _http_server.js:239:68
      5   38.5%        LazyCompile: ~writeHead _http_server.js:244:19
      5  100.0%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:290:19
      5  100.0%            LazyCompile: ~_implicitHeader _http_server.js:239:68
     12    1.7%      LazyCompile: ~copyHeader /app/node_modules/dd-trace/packages/dd-trace/src/encode/index.js:124:21
     12  100.0%        LazyCompile: ~encode /app/node_modules/dd-trace/packages/dd-trace/src/encode/index.js:60:17
     12  100.0%          LazyCompile: ~_encode /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:100:11
     12  100.0%            LazyCompile: ~append /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:23:10
     12    1.7%      LazyCompile: *listOnTimeout internal/timers.js:497:25
     11   91.7%        LazyCompile: ~processTimers internal/timers.js:477:25
      1    8.3%        LazyCompile: *processTimers internal/timers.js:477:25
     11    1.6%      LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
      1    9.1%        LazyCompile: ~runNextTicks internal/process/task_queues.js:60:22
      1  100.0%          LazyCompile: *processTimers internal/timers.js:477:25
     11    1.6%      LazyCompile: ~_add /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:54:8      9   81.8%        LazyCompile: ~gauge /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:24:9
      3   33.3%          LazyCompile: ~captureMemoryUsage /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:178:29
      3  100.0%            LazyCompile: ~captureCommonMetrics /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:249:31
      2   22.2%          LazyCompile: ~captureNativeMetrics /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:258:31
      2  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
      2   22.2%          LazyCompile: ~captureHeapStats /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:194:27
      2  100.0%            LazyCompile: ~captureCommonMetrics /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:249:31
      1   11.1%          LazyCompile: ~histogram /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:309:20
      1  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:276:33
      1   11.1%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:224:26
      1  100.0%            /usr/local/bin/node
      1    9.1%        LazyCompile: ~increment /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:28:13
      1  100.0%          LazyCompile: ~histogram /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:309:20
      1  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:276:33
      1    9.1%        LazyCompile: ~captureGauges /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:222:24
      1  100.0%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:224:26
      1  100.0%            /usr/local/bin/node
     11    1.6%      LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:66:56
     11  100.0%        LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/request.js:31:19
     11  100.0%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
      7   63.6%            LazyCompile: *activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:8:12
      4   36.4%            LazyCompile: *_activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:45:13
      9    1.3%      LazyCompile: ~fromStringFast buffer.js:423:24
      8   88.9%        LazyCompile: ~fromString buffer.js:442:20
      6   75.0%          LazyCompile: ~from buffer.js:304:28
      6  100.0%            LazyCompile: ~_enqueue /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:77:12
      1   12.5%          LazyCompile: ~flush /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:32:9
      1  100.0%            LazyCompile: ~_enqueue /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:77:12
      1   12.5%          LazyCompile: ~captureHistograms /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:240:28
      1  100.0%            LazyCompile: ~_enqueue /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:77:12
      1   11.1%        LazyCompile: ~from buffer.js:304:28
      1  100.0%          LazyCompile: ~_write /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:66:10
      1  100.0%            LazyCompile: ~_add /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:54:8
      9    1.3%      LazyCompile: ~exports.floatFormatter /app/node_modules/hdr-histogram-js/formatters.js:15:35
      9  100.0%        Eval: ~<anonymous> /app/node_modules/hdr-histogram-js/HistogramLogWriter.js:1:1
      9  100.0%          LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
      9  100.0%            LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
      9    1.3%      LazyCompile: ~captureMemoryUsage /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:178:29
      8   88.9%        LazyCompile: ~captureCommonMetrics /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:249:31
      7   87.5%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
      4   57.1%            LazyCompile: *listOnTimeout internal/timers.js:497:25
      3   42.9%            LazyCompile: ~listOnTimeout internal/timers.js:497:25
      1   12.5%          LazyCompile: ~captureCommonMetrics /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:249:31
      1  100.0%            LazyCompile: *listOnTimeout internal/timers.js:497:25
      1   11.1%        LazyCompile: ~captureProcess /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:190:25
      1  100.0%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
      1  100.0%            LazyCompile: *listOnTimeout internal/timers.js:497:25
      8    1.2%      LazyCompile: ~Socket.send dgram.js:548:33
      8  100.0%        LazyCompile: ~_send /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:46:9
      8  100.0%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:41:23
      8  100.0%            /usr/local/bin/node
      8    1.2%      LazyCompile: ~OutgoingMessage _http_outgoing.js:82:25
      7   87.5%        LazyCompile: ~ServerResponse _http_server.js:153:24
      7  100.0%          LazyCompile: ~parserOnIncoming _http_server.js:724:26
      7  100.0%            LazyCompile: ~parserOnHeadersComplete _http_common.js:72:33
      1   12.5%        LazyCompile: ~ClientRequest _http_client.js:88:23
      1  100.0%          LazyCompile: ~request http.js:46:17
      1  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
      8    1.2%      LazyCompile: *writeMap /app/node_modules/dd-trace/packages/dd-trace/src/encode/index.js:153:19
      8  100.0%        LazyCompile: ~encode /app/node_modules/dd-trace/packages/dd-trace/src/encode/index.js:60:17
      8  100.0%          LazyCompile: ~_encode /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:100:11
      8  100.0%            LazyCompile: ~append /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:23:10
      7    1.0%      LazyCompile: ~getOptions /app/node_modules/dd-trace/packages/datadog-plugin-net/src/index.js:68:21
      7  100.0%        LazyCompile: ~getOptions /app/node_modules/dd-trace/packages/datadog-plugin-net/src/index.js:68:21
      7  100.0%          LazyCompile: ~connectWithTrace /app/node_modules/dd-trace/packages/datadog-plugin-net/src/index.js:8:38
      7  100.0%            LazyCompile: ~connect net.js:174:17
      7    1.0%      LazyCompile: ~_write /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:66:10
      7  100.0%        LazyCompile: ~_add /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:54:8
      6   85.7%          LazyCompile: ~gauge /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:24:9
      5   83.3%            LazyCompile: ~captureHeapStats /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:194:27
      1   16.7%            LazyCompile: ~_add /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:54:8
      1   14.3%          LazyCompile: ~memoryUsage internal/process/per_thread.js:150:23
      1  100.0%            LazyCompile: ~captureHeapStats /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:194:27

  13571   46.3%  /usr/local/bin/node
   5026   37.0%    /usr/local/bin/node
    398    7.9%      /usr/local/bin/node
     48   12.1%        LazyCompile: ~_request /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:39:12
     48  100.0%          LazyCompile: ~flush /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:29:9
     48  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/index.js:13:39
     27    6.8%        LazyCompile: *emitInitNative internal/async_hooks.js:139:24
      9   33.3%          /usr/local/bin/node
      5   55.6%            LazyCompile: ~Socket._final net.js:400:35
      3   33.3%            LazyCompile: ~tickOnSocket _http_client.js:728:22
      1   11.1%            LazyCompile: ~internalConnect net.js:863:25
      7   25.9%          LazyCompile: *endReadable _stream_readable.js:1207:21
      7  100.0%            LazyCompile: ~Readable.read _stream_readable.js:383:35
      7   25.9%          LazyCompile: *Readable.resume _stream_readable.js:937:37
      7  100.0%            LazyCompile: ~_dump _http_incoming.js:291:49
      2    7.4%          LazyCompile: ~emitInitScript internal/async_hooks.js:405:24
      2  100.0%            LazyCompile: *readableAddChunk _stream_readable.js:225:26
      2    7.4%          LazyCompile: *resume _stream_readable.js:951:16
      2  100.0%            LazyCompile: ~Readable.resume _stream_readable.js:937:37
     26    6.5%        LazyCompile: ~expressInit /app/node_modules/express/lib/middleware/init.js:29:30
     26  100.0%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/datadog-plugin-router/src/index.js:108:64
     26  100.0%            LazyCompile: *_activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:45:13
     24    6.0%        LazyCompile: ~captureNativeMetrics /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:258:31
     23   95.8%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
     15   65.2%            LazyCompile: *listOnTimeout internal/timers.js:497:25
      8   34.8%            LazyCompile: ~listOnTimeout internal/timers.js:497:25
      1    4.2%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:276:33
      1  100.0%            LazyCompile: ~listOnTimeout internal/timers.js:497:25
     24    6.0%        LazyCompile: ~addRequestTags /app/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:348:25
     24  100.0%          LazyCompile: ~finish /app/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:231:17
     24  100.0%            LazyCompile: ~res._datadog_end /app/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:261:31
     22    5.5%        LazyCompile: *addListenerWithTrace /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:144:40
      6   27.3%          LazyCompile: ~Socket.connect net.js:925:36
      4   66.7%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
      2   33.3%            LazyCompile: *<anonymous> /app/node_modules/express/lib/router/index.js:629:19
      5   22.7%          LazyCompile: ~tickOnSocket _http_client.js:728:22
      5  100.0%            LazyCompile: ~onSocketNT _http_client.js:794:20
      3   13.6%          LazyCompile: *connectionListenerInternal _http_server.js:407:36
      3  100.0%            LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      2    9.1%          LazyCompile: ~setSocketTimeout _http_client.js:854:26
      2  100.0%            LazyCompile: ~<anonymous> _http_client.js:848:25
      2    9.1%          LazyCompile: ~connectionListenerInternal _http_server.js:407:36
      1   50.0%            LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      1   50.0%            LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      2    9.1%          LazyCompile: ~<anonymous> _http_client.js:782:22
      1   50.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
      1   50.0%            LazyCompile: *<anonymous> /app/node_modules/express/lib/router/index.js:629:19
      1    4.5%          LazyCompile: ~setupListeners /app/node_modules/dd-trace/packages/datadog-plugin-net/src/index.js:89:25
      1  100.0%            LazyCompile: ~wrapTcp /app/node_modules/dd-trace/packages/datadog-plugin-net/src/index.js:25:18
      1    4.5%          LazyCompile: ~req.emit /app/node_modules/dd-trace/packages/datadog-plugin-http/src/client.js:79:27
      1  100.0%            LazyCompile: ~parserOnIncomingClient _http_client.js:575:32
     20    5.0%        LazyCompile: ~startSpan /app/node_modules/dd-trace/packages/datadog-plugin-net/src/index.js:55:20     20  100.0%          LazyCompile: ~wrapTcp /app/node_modules/dd-trace/packages/datadog-plugin-net/src/index.js:25:18     20  100.0%            LazyCompile: ~connectWithTrace /app/node_modules/dd-trace/packages/datadog-plugin-net/src/index.js:8:38
     18    4.5%        LazyCompile: ~ClientRequest _http_client.js:88:23
     18  100.0%          LazyCompile: ~request http.js:46:17
     17   94.4%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
      1    5.6%            LazyCompile: *<anonymous> /app/node_modules/express/lib/router/index.js:629:19
     17    4.3%        LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/datadog-plugin-http/src/client.js:251:15
     17  100.0%          /usr/local/bin/node
     17  100.0%            LazyCompile: ~hasAmazonSignature /app/node_modules/dd-trace/packages/datadog-plugin-http/src/client.js:244:29
     10    2.5%        LazyCompile: *_destroy /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:130:12
     10  100.0%          LazyCompile: *emitHook internal/async_hooks.js:170:18
      9    2.3%        LazyCompile: ~_finish /app/node_modules/dd-trace/packages/dd-trace/src/opentracing/span.js:106:11      9  100.0%          LazyCompile: ~Span.finish /app/node_modules/opentracing/lib/span.js:159:38
      4   44.4%            LazyCompile: ~finish /app/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:125:10
      3   33.3%            LazyCompile: ~finish /app/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:231:17
      2   22.2%            LazyCompile: ~finishMiddleware /app/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:244:27
      9    2.3%        LazyCompile: *nextTick internal/process/task_queues.js:105:18
      3   33.3%          LazyCompile: ~resume _stream_readable.js:951:16
      3  100.0%            LazyCompile: ~Readable.resume _stream_readable.js:937:37
      1   11.1%          LazyCompile: ~onwrite _stream_writable.js:394:17
      1  100.0%            LazyCompile: ~afterWriteDispatched internal/stream_base_commons.js:149:30
      1   11.1%          LazyCompile: ~lookup dns.js:92:16
      1  100.0%            LazyCompile: ~lookup4 internal/dgram.js:17:17
      1   11.1%          LazyCompile: ~endReadable _stream_readable.js:1207:21
      1  100.0%            LazyCompile: ~Readable.read _stream_readable.js:383:35
      1   11.1%          LazyCompile: ~afterDns dgram.js:626:20
      1  100.0%            LazyCompile: ~lookup4 internal/dgram.js:17:17
      1   11.1%          LazyCompile: ~<anonymous> internal/streams/destroy.js:36:30
      1  100.0%            LazyCompile: ~Socket._destroy net.js:650:37
      1   11.1%          LazyCompile: *destroy internal/streams/destroy.js:5:17
      1  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
      8    2.0%        LazyCompile: ~_getModules /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/loader.js:38:15
      8  100.0%          LazyCompile: ~load /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/loader.js:32:8
      8  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/instrumenter.js:140:18
      8    2.0%        LazyCompile: ~FastBuffer internal/buffer.js:945:1
      8  100.0%          LazyCompile: ~createUnsafeBuffer buffer.js:147:28
      4   50.0%            LazyCompile: ~createPool buffer.js:156:20
      4   50.0%            LazyCompile: *allocUnsafe buffer.js:383:42
      8    2.0%        LazyCompile: *writeMap /app/node_modules/dd-trace/packages/dd-trace/src/encode/index.js:153:19
      8  100.0%          LazyCompile: ~encode /app/node_modules/dd-trace/packages/dd-trace/src/encode/index.js:60:17
      8  100.0%            LazyCompile: ~_encode /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:100:11
      8    2.0%        LazyCompile: *getMapPrefixes /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:56:25
      8  100.0%          LazyCompile: ~load /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/loader.js:32:8
      8  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/instrumenter.js:140:18
      7    1.8%        LazyCompile: ~getHeaders _http_outgoing.js:565:59
      7  100.0%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:290:19
      7  100.0%            LazyCompile: ~_implicitHeader _http_server.js:239:68
      7    1.8%        LazyCompile: ~checkInvalidHeaderChar _http_common.js:221:32
      7  100.0%          LazyCompile: ~<anonymous> _http_outgoing.js:521:45
      7  100.0%            LazyCompile: *hidden internal/errors.js:282:25
      7    1.8%        LazyCompile: ~captureCounters /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:230:26
      7  100.0%          LazyCompile: ~captureCommonMetrics /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:249:31
      7  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
      6    1.5%        LazyCompile: ~calculateServerName _http_agent.js:292:29
      6  100.0%          LazyCompile: ~addRequest _http_agent.js:193:49
      6  100.0%            LazyCompile: ~ClientRequest _http_client.js:88:23
      6    1.5%        LazyCompile: *add /app/node_modules/dd-trace/packages/dd-trace/src/tagger.js:5:14
      3   50.0%          LazyCompile: ~_addTags /app/node_modules/dd-trace/packages/dd-trace/src/opentracing/span.js:102:12
      3  100.0%            LazyCompile: ~Span.setTag /app/node_modules/opentracing/lib/span.js:83:38
      3   50.0%          LazyCompile: *wrapCallHandle /app/node_modules/dd-trace/packages/datadog-plugin-router/src/index.js:44:31
      2   66.7%            LazyCompile: ~handle /app/node_modules/express/lib/router/layer.js:86:49
      1   33.3%            LazyCompile: *handle /app/node_modules/express/lib/router/layer.js:86:49
      5    1.3%        LazyCompile: ~_getPriority /app/node_modules/dd-trace/packages/dd-trace/src/priority_sampler.js:87:16
      3   60.0%          LazyCompile: ~sample /app/node_modules/dd-trace/packages/dd-trace/src/priority_sampler.js:41:10      3  100.0%            LazyCompile: ~process /app/node_modules/dd-trace/packages/dd-trace/src/span_processor.js:10:11
      2   40.0%          LazyCompile: *<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:224:26
      2  100.0%            LazyCompile: ~Span.finish /app/node_modules/opentracing/lib/span.js:159:38
      5    1.3%        LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:39:24
      5  100.0%          LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
      4    1.0%        LazyCompile: ~extractAnalytics /app/node_modules/dd-trace/packages/dd-trace/src/format.js:108:27
      3   75.0%          LazyCompile: *<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:224:26
      3  100.0%            LazyCompile: ~Span.finish /app/node_modules/opentracing/lib/span.js:159:38
      1   25.0%          LazyCompile: ~format /app/node_modules/dd-trace/packages/dd-trace/src/format.js:21:17
      1  100.0%            /usr/local/bin/node
      4    1.0%        LazyCompile: ~EventEmitter.init events.js:130:29
      4  100.0%          LazyCompile: ~EventEmitter events.js:64:22
      4  100.0%            LazyCompile: ~Stream internal/streams/legacy.js:9:16
    336    6.7%      LazyCompile: ~internalConnect net.js:863:25
    210   62.5%        LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
    210  100.0%          LazyCompile: ~<anonymous> net.js:1005:73
    210  100.0%            LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
    126   37.5%        LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
    126  100.0%          LazyCompile: ~<anonymous> net.js:1005:73
    126  100.0%            LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
    334    6.6%      LazyCompile: ~writevGeneric internal/stream_base_commons.js:116:23
    334  100.0%        LazyCompile: ~Socket._writeGeneric net.js:756:42
    262   78.4%          LazyCompile: ~Socket._writev net.js:788:36
    262  100.0%            LazyCompile: ~doWrite _stream_writable.js:367:17
     72   21.6%          LazyCompile: ~connect net.js:763:42
     49   68.1%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
     10   13.9%            LazyCompile: *<anonymous> /app/node_modules/express/lib/router/index.js:629:19
      8   11.1%            LazyCompile: *bound /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:52:28
      5    6.9%            LazyCompile: *<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
    151    3.0%      LazyCompile: ~Socket._destroy net.js:650:37
    151  100.0%        LazyCompile: ~destroy internal/streams/destroy.js:5:17
    145   96.0%          LazyCompile: ~onReadableStreamEnd net.js:627:29
    124   85.5%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
     11    7.6%            LazyCompile: *bound /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:52:28
     10    6.9%            LazyCompile: *<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
      4    2.6%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
      3   75.0%            LazyCompile: *_activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:45:13
      1   25.0%            LazyCompile: *activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:8:12
      2    1.3%          LazyCompile: *<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
      2  100.0%            LazyCompile: *activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:8:12
    120    2.4%      LazyCompile: ~doSend dgram.js:641:16
     75   62.5%        LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
     74   98.7%          LazyCompile: ~afterDns dgram.js:626:20
     74  100.0%            LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
      1    1.3%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:299:46
      1  100.0%            LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
     45   37.5%        LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
     44   97.8%          LazyCompile: ~afterDns dgram.js:626:20
     44  100.0%            LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
      1    2.2%          LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
    119    2.4%      LazyCompile: *destroy internal/streams/destroy.js:5:17
    115   96.6%        LazyCompile: ~onReadableStreamEnd net.js:627:29
     70   60.9%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
     70  100.0%            LazyCompile: *activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:8:12
     28   24.3%          LazyCompile: *<anonymous> /app/node_modules/express/lib/router/index.js:629:19
     28  100.0%            LazyCompile: *endReadableNT _stream_readable.js:1217:23
     12   10.4%          LazyCompile: *<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
     12  100.0%            LazyCompile: *activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:8:12
      5    4.3%          LazyCompile: *bound /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:52:28
      5  100.0%            LazyCompile: *endReadableNT _stream_readable.js:1217:23
      2    1.7%        LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
      2  100.0%          LazyCompile: *activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:8:12
      2  100.0%            LazyCompile: ~bound /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:52:28
      2    1.7%        LazyCompile: *<anonymous> /app/node_modules/express/lib/router/index.js:629:19
      2  100.0%          LazyCompile: *onceWrapper events.js:416:21
      2  100.0%            LazyCompile: *finishMaybe _stream_writable.js:623:21
     80    1.6%      LazyCompile: *emitInitNative internal/async_hooks.js:139:24
     24   30.0%        /usr/local/bin/node
      6   25.0%          LazyCompile: ~Socket._final net.js:400:35
      6  100.0%            LazyCompile: ~callFinal _stream_writable.js:597:19
      5   20.8%          LazyCompile: *connectionListenerInternal _http_server.js:407:36
      5  100.0%            LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      4   16.7%          LazyCompile: ~internalConnect net.js:863:25
      3   75.0%            LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      1   25.0%            LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      4   16.7%          LazyCompile: ~connectionListenerInternal _http_server.js:407:36
      3   75.0%            LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      1   25.0%            LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      3   12.5%          LazyCompile: ~Socket.connect net.js:925:36
      3  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
      2    8.3%          LazyCompile: ~tickOnSocket _http_client.js:728:22
      2  100.0%            LazyCompile: ~onSocketNT _http_client.js:794:20
     17   21.3%        LazyCompile: ~emitInitScript internal/async_hooks.js:405:24
     13   76.5%          LazyCompile: ~initAsyncResource internal/timers.js:148:27
      7   53.8%            LazyCompile: ~Timeout internal/timers.js:158:17
      4   30.8%            LazyCompile: *_storeHeader _http_outgoing.js:352:22
      2   15.4%            LazyCompile: ~Immediate timers.js:208:14
      4   23.5%          LazyCompile: *readableAddChunk _stream_readable.js:225:26
      4  100.0%            LazyCompile: ~Readable.push _stream_readable.js:216:35
      6    7.5%        LazyCompile: *endReadable _stream_readable.js:1207:21
      6  100.0%          LazyCompile: ~Readable.read _stream_readable.js:383:35
      2   33.3%            LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
      2   33.3%            LazyCompile: ~flow _stream_readable.js:982:14
      1   16.7%            LazyCompile: ~resume_ _stream_readable.js:958:17
      1   16.7%            LazyCompile: ~Socket.read net.js:617:33
      2    2.5%        LazyCompile: *setStreamTimeout internal/stream_base_commons.js:234:26
      1   50.0%          LazyCompile: ~setTimeout _http_incoming.js:96:59
      1  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/request.js:25:39
      1   50.0%          LazyCompile: ~<anonymous> _http_client.js:856:34
      1  100.0%            LazyCompile: *<anonymous> /app/node_modules/express/lib/router/index.js:629:19
      2    2.5%        LazyCompile: *Readable.resume _stream_readable.js:937:37
      1   50.0%          LazyCompile: ~Socket.resume net.js:608:35
      1  100.0%            LazyCompile: *Readable.on _stream_readable.js:850:33
      1   50.0%          LazyCompile: *Readable.on _stream_readable.js:850:33
      1  100.0%            LazyCompile: *addListenerWithTrace /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:144:40
      1    1.3%        LazyCompile: *onwrite _stream_writable.js:394:17
      1  100.0%          LazyCompile: ~afterWriteDispatched internal/stream_base_commons.js:149:30
      1  100.0%            LazyCompile: ~writevGeneric internal/stream_base_commons.js:116:23
     77    1.5%      LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
     70   90.9%        LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      5    7.1%          Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      4    5.7%          LazyCompile: ~setupPrepareStackTrace internal/bootstrap/node.js:250:32
      4  100.0%            Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      4    5.7%          Eval: ~<anonymous> stream.js:1:1
      4  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      4    5.7%          Eval: ~<anonymous> http.js:1:1
      4  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      4    5.7%          Eval: ~<anonymous> events.js:1:1
      4  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      4    5.7%          Eval: ~<anonymous> crypto.js:1:1
      4  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      3    4.3%          Eval: ~<anonymous> internal/url.js:1:1
      3  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      3    4.3%          Eval: ~<anonymous> internal/modules/cjs/loader.js:1:1
      3  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2    2.9%          LazyCompile: ~setupBuffer internal/bootstrap/node.js:298:21
      2  100.0%            Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      2    2.9%          LazyCompile: ~initializeCJSLoader internal/bootstrap/pre_execution.js:399:29
      2  100.0%            LazyCompile: ~prepareMainThreadExecution internal/bootstrap/pre_execution.js:14:36
      2    2.9%          Eval: ~<anonymous> timers.js:1:1
      2  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2    2.9%          Eval: ~<anonymous> internal/source_map/source_map_cache.js:1:1
      2  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2    2.9%          Eval: ~<anonymous> internal/console/global.js:1:1
      2  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2    2.9%          Eval: ~<anonymous> internal/cluster/master.js:1:1
      2  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2    2.9%          Eval: ~<anonymous> _http_client.js:1:1
      2  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2    2.9%          Eval: ~<anonymous> _http_agent.js:1:1
      2  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          LazyCompile: ~setupProcessObject internal/bootstrap/node.js:269:28
      1  100.0%            Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      1    1.4%          LazyCompile: ~lazyLoadStreams fs.js:1915:25
      1  100.0%            LazyCompile: ~get ReadStream fs.js:2018:17
      1    1.4%          LazyCompile: ~get fs.js:2073:8
      1  100.0%            /usr/local/bin/node
      1    1.4%          LazyCompile: ~get dns.js:324:8
      1  100.0%            /usr/local/bin/node
      1    1.4%          LazyCompile: ~createGlobalConsole internal/bootstrap/node.js:315:29
      1  100.0%            Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      1    1.4%          Eval: ~<anonymous> v8.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> tty.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> tls.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> internal/util/inspect.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> internal/timers.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> internal/streams/lazy_transform.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> internal/process/task_queues.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> internal/process/esm_loader.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> internal/modules/esm/loader.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> internal/modules/cjs/helpers.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> internal/crypto/keygen.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> https.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> fs.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> child_process.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> buffer.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> _tls_wrap.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> _stream_readable.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> _http_common.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      7    9.1%        LazyCompile: ~compileForPublicLoader internal/bootstrap/loaders.js:212:25
      7  100.0%          LazyCompile: ~loadNativeModule internal/modules/cjs/helpers.js:21:26
      7  100.0%            LazyCompile: ~Module._load internal/modules/cjs/loader.js:877:24
     74    1.5%      LazyCompile: *addListenerWithTrace /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:144:40
     16   21.6%        LazyCompile: ~connectionListenerInternal _http_server.js:407:36
     11   68.8%          LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
     11  100.0%            LazyCompile: ~connectionListener _http_server.js:401:28
      5   31.3%          LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      5  100.0%            LazyCompile: ~connectionListener _http_server.js:401:28
     12   16.2%        LazyCompile: ~tickOnSocket _http_client.js:728:22
     12  100.0%          LazyCompile: ~onSocketNT _http_client.js:794:20
     12  100.0%            LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
      9   12.2%        LazyCompile: ~Socket net.js:264:16
      8   88.9%          LazyCompile: ~onconnection net.js:1526:22
      1   11.1%          LazyCompile: *onconnection net.js:1526:22
      6    8.1%        LazyCompile: ~setupListeners /app/node_modules/dd-trace/packages/datadog-plugin-net/src/index.js:89:25
      6  100.0%          LazyCompile: ~wrapTcp /app/node_modules/dd-trace/packages/datadog-plugin-net/src/index.js:25:18      6  100.0%            LazyCompile: ~connectWithTrace /app/node_modules/dd-trace/packages/datadog-plugin-net/src/index.js:8:38
      6    8.1%        LazyCompile: ~Socket.destroySoon net.js:639:40
      6  100.0%          LazyCompile: ~resOnFinish _http_server.js:678:21
      5   83.3%            LazyCompile: *emit events.js:263:44
      1   16.7%            LazyCompile: ~emit events.js:263:44
      5    6.8%        LazyCompile: ~installListeners _http_agent.js:323:26
      5  100.0%          LazyCompile: ~<anonymous> _http_agent.js:275:25
      5  100.0%            LazyCompile: ~<anonymous> internal/util.js:389:18
      3    4.1%        LazyCompile: ~req.emit /app/node_modules/dd-trace/packages/datadog-plugin-http/src/client.js:79:27
      3  100.0%          LazyCompile: ~parserOnIncomingClient _http_client.js:575:32
      3  100.0%            LazyCompile: ~parserOnHeadersComplete _http_common.js:72:33
      3    4.1%        LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/datadog-plugin-net/src/index.js:114:18
      3  100.0%          /usr/local/bin/node
      3  100.0%            LazyCompile: ~setupListeners /app/node_modules/dd-trace/packages/datadog-plugin-net/src/index.js:89:25
      2    2.7%        LazyCompile: ~socketListenerWrap _http_server.js:835:37
      2  100.0%          LazyCompile: ~assignSocket _http_server.js:214:62
      2  100.0%            LazyCompile: ~parserOnIncoming _http_server.js:724:26
      2    2.7%        LazyCompile: ~parserOnIncomingClient _http_client.js:575:32
      2  100.0%          LazyCompile: ~parserOnHeadersComplete _http_common.js:72:33
      2  100.0%            /usr/local/bin/node
      2    2.7%        LazyCompile: ~listenSocketTimeout _http_client.js:772:29
      2  100.0%          LazyCompile: ~setTimeout _http_client.js:836:57
      2  100.0%            LazyCompile: ~request /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/request.js:9:18
      2    2.7%        LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/request.js:25:39
      1   50.0%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
      1  100.0%            LazyCompile: *activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:8:12
      1   50.0%          LazyCompile: *<anonymous> /app/node_modules/express/lib/router/index.js:629:19
      1  100.0%            LazyCompile: *onceWrapper events.js:416:21
      2    2.7%        LazyCompile: *connectionListenerInternal _http_server.js:407:36
      2  100.0%          LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      2  100.0%            LazyCompile: ~connectionListener _http_server.js:401:28
      1    1.4%        LazyCompile: ~setTimeout _http_client.js:836:57
      1  100.0%          LazyCompile: ~request /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/request.js:9:18
      1  100.0%            LazyCompile: ~_request /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:39:12
      1    1.4%        LazyCompile: ~request /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/request.js:9:18
      1  100.0%          LazyCompile: ~_request /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:39:12
      1  100.0%            LazyCompile: ~flush /app/node_modules/dd-trace/packages/dd-trace/src/exporters/agent/writer.js:29:9
      1    1.4%        LazyCompile: ~Socket.connect net.js:925:36
      1  100.0%          LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
      1  100.0%            LazyCompile: *activate /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:8:12
      1    1.4%        LazyCompile: ~Socket._writeGeneric net.js:756:42
      1  100.0%          LazyCompile: ~Socket._writev net.js:788:36
      1  100.0%            LazyCompile: ~doWrite _stream_writable.js:367:17
     69    1.4%      LazyCompile: ~wrapSafe internal/modules/cjs/loader.js:1101:18
     69  100.0%        LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
     69  100.0%          LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
     69  100.0%            LazyCompile: ~Module.load internal/modules/cjs/loader.js:1037:33
     67    1.3%      LazyCompile: ~captureCommonMetrics /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:249:31
     67  100.0%        LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
     47   70.1%          LazyCompile: *listOnTimeout internal/timers.js:497:25
     29   61.7%            LazyCompile: ~processTimers internal/timers.js:477:25
     18   38.3%            LazyCompile: *processTimers internal/timers.js:477:25
     20   29.9%          LazyCompile: ~listOnTimeout internal/timers.js:497:25
     20  100.0%            LazyCompile: ~processTimers internal/timers.js:477:25
     67    1.3%      LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
     48   71.6%        LazyCompile: *listOnTimeout internal/timers.js:497:25
     34   70.8%          LazyCompile: ~processTimers internal/timers.js:477:25
     14   29.2%          LazyCompile: *processTimers internal/timers.js:477:25
     19   28.4%        LazyCompile: ~listOnTimeout internal/timers.js:497:25
     19  100.0%          LazyCompile: ~processTimers internal/timers.js:477:25
     59    1.2%      LazyCompile: *_bindEmitter /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:69:16
     59  100.0%        LazyCompile: ~bind /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:22:8
     33   55.9%          LazyCompile: ~wrapEvents /app/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:335:21
     33  100.0%            LazyCompile: ~instrument /app/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:51:14
     15   25.4%          LazyCompile: ~requestTrace /app/node_modules/dd-trace/packages/datadog-plugin-http/src/client.js:30:34
     15  100.0%            LazyCompile: ~request /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/request.js:9:18
     11   18.6%          LazyCompile: ~req.emit /app/node_modules/dd-trace/packages/datadog-plugin-http/src/client.js:79:27
     11  100.0%            LazyCompile: ~parserOnIncomingClient _http_client.js:575:32
     56    1.1%      LazyCompile: ~Socket._final net.js:400:35
     56  100.0%        LazyCompile: ~callFinal _stream_writable.js:597:19
     56  100.0%          LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
     52    1.0%      LazyCompile: *nextTick internal/process/task_queues.js:105:18
     11   21.2%        LazyCompile: ~resume _stream_readable.js:951:16
     11  100.0%          LazyCompile: ~Readable.resume _stream_readable.js:937:37
      9   81.8%            LazyCompile: ~Socket.resume net.js:608:35
      1    9.1%            LazyCompile: ~send /app/node_modules/finalhandler/index.js:272:15
      1    9.1%            LazyCompile: ~Readable.on _stream_readable.js:850:33
      9   17.3%        LazyCompile: ~endReadable _stream_readable.js:1207:21
      9  100.0%          LazyCompile: ~Readable.read _stream_readable.js:383:35
      5   55.6%            LazyCompile: ~Socket.read net.js:617:33
      4   44.4%            LazyCompile: ~resume_ _stream_readable.js:958:17
      6   11.5%        LazyCompile: ~onwrite _stream_writable.js:394:17
      6  100.0%          LazyCompile: ~afterWriteDispatched internal/stream_base_commons.js:149:30
      6  100.0%            LazyCompile: ~writevGeneric internal/stream_base_commons.js:116:23
      6   11.5%        LazyCompile: ~lookup dns.js:92:16
      3   50.0%          LazyCompile: ~lookup4 internal/dgram.js:17:17
      3  100.0%            LazyCompile: ~Socket.send dgram.js:548:33
      3   50.0%          LazyCompile: ~flush /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:32:9
      3  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
      4    7.7%        LazyCompile: ~<anonymous> internal/streams/destroy.js:36:30
      4  100.0%          LazyCompile: ~Socket._destroy net.js:650:37
      4  100.0%            LazyCompile: ~destroy internal/streams/destroy.js:5:17
      4    7.7%        LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      4  100.0%          LazyCompile: ~lookupAndConnect net.js:980:26
      4  100.0%            LazyCompile: ~Socket.connect net.js:925:36
      3    5.8%        LazyCompile: ~emitReadable _stream_readable.js:547:22
      3  100.0%          LazyCompile: ~onEofChunk _stream_readable.js:517:20
      3  100.0%            LazyCompile: ~readableAddChunk _stream_readable.js:225:26
      3    5.8%        LazyCompile: *destroy internal/streams/destroy.js:5:17
      3  100.0%          LazyCompile: ~onReadableStreamEnd net.js:627:29
      2   66.7%            LazyCompile: *<anonymous> /app/node_modules/express/lib/router/index.js:629:19
      1   33.3%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/scope/base.js:53:43
      2    3.8%        LazyCompile: ~resOnFinish _http_server.js:678:21
      2  100.0%          LazyCompile: *emit events.js:263:44
      2  100.0%            LazyCompile: ~onFinish _http_outgoing.js:739:18
      1    1.9%        LazyCompile: ~onSocket _http_client.js:788:53
      1  100.0%          LazyCompile: ~setRequestSocket _http_agent.js:434:26
      1  100.0%            LazyCompile: ~<anonymous> _http_agent.js:245:37
      1    1.9%        LazyCompile: ~maybeReadMore _stream_readable.js:586:23
      1  100.0%          LazyCompile: ~addChunk _stream_readable.js:293:18
      1  100.0%            LazyCompile: *readableAddChunk _stream_readable.js:225:26
      1    1.9%        LazyCompile: ~doSend dgram.js:641:16
      1  100.0%          LazyCompile: ~flush /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:32:9
      1  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
      1    1.9%        LazyCompile: *Socket.end net.js:587:32
      1  100.0%          LazyCompile: ~Socket.destroySoon net.js:639:40
      1  100.0%            LazyCompile: ~resOnFinish _http_server.js:678:21```

kaievns commented 4 years ago

and this one with plugins disabled



 [Shared libraries]:
   ticks  total  nonlib   name
   8223   66.0%          /lib/ld-musl-x86_64.so.1
   3758   30.2%          /usr/local/bin/node
     32    0.3%          /usr/lib/libstdc++.so.6.0.27
      6    0.0%          [vdso]

 [JavaScript]:
   ticks  total  nonlib   name
     38    0.3%    8.5%  LazyCompile: *_destroy /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:130:12
     19    0.2%    4.3%  LazyCompile: *Readable.read _stream_readable.js:383:35
     17    0.1%    3.8%  LazyCompile: *emitHook internal/async_hooks.js:170:18
     15    0.1%    3.4%  LazyCompile: *processTicksAndRejections internal/process/task_queues.js:69:35
     15    0.1%    3.4%  LazyCompile: *emitInitNative internal/async_hooks.js:139:24
     13    0.1%    2.9%  LazyCompile: *connectionListenerInternal _http_server.js:407:36
     12    0.1%    2.7%  LazyCompile: *nextTick internal/process/task_queues.js:105:18
     12    0.1%    2.7%  LazyCompile: *emitInitScript internal/async_hooks.js:405:24
     11    0.1%    2.5%  LazyCompile: *emit events.js:263:44
     10    0.1%    2.2%  LazyCompile: *listOnTimeout internal/timers.js:497:25
      9    0.1%    2.0%  LazyCompile: *popAsyncContext internal/async_hooks.js:473:25
      9    0.1%    2.0%  LazyCompile: *ReadableState _stream_readable.js:87:23
      9    0.1%    2.0%  LazyCompile: *<anonymous> internal/util/debuglog.js:63:18
      8    0.1%    1.8%  LazyCompile: *next /app/node_modules/express/lib/router/index.js:176:16
      8    0.1%    1.8%  LazyCompile: *_before /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:121:11
      7    0.1%    1.6%  LazyCompile: *count /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:116:11
      7    0.1%    1.6%  LazyCompile: *Socket.resume net.js:608:35
      6    0.0%    1.3%  LazyCompile: *hasHooks internal/async_hooks.js:384:18
      6    0.0%    1.3%  LazyCompile: *get net.js:1679:6
      6    0.0%    1.3%  LazyCompile: *_storeHeader _http_outgoing.js:352:22
      6    0.0%    1.3%  LazyCompile: *_after /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:126:10
      6    0.0%    1.3%  LazyCompile: *Socket net.js:264:16
      6    0.0%    1.3%  LazyCompile: *Readable.on _stream_readable.js:850:33
      5    0.0%    1.1%  LazyCompile: *handle /app/node_modules/express/lib/router/index.js:136:31
      5    0.0%    1.1%  LazyCompile: *getArrayPrefixes /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:39:27
      4    0.0%    0.9%  LazyCompile: *parserOnIncoming _http_server.js:724:26
      4    0.0%    0.9%  LazyCompile: *getStrPrefixes /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:5:25
      4    0.0%    0.9%  LazyCompile: *gauge /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:24:9
      3    0.0%    0.7%  LazyCompile: *processPromiseRejections internal/process/promises.js:171:34
      3    0.0%    0.7%  LazyCompile: *normalizeString path.js:52:25
      3    0.0%    0.7%  LazyCompile: *initAsyncResource internal/timers.js:148:27
      3    0.0%    0.7%  LazyCompile: *handle /app/node_modules/express/lib/router/layer.js:86:49
      3    0.0%    0.7%  LazyCompile: *get _stream_duplex.js:90:8
      3    0.0%    0.7%  LazyCompile: *_addListener events.js:343:22
      3    0.0%    0.7%  LazyCompile: *Readable.removeListener _stream_readable.js:880:45
      2    0.0%    0.4%  LazyCompile: *writeHead _http_server.js:244:19
      2    0.0%    0.4%  LazyCompile: *push internal/fixed_queue.js:75:7
      2    0.0%    0.4%  LazyCompile: *parseurl /app/node_modules/parseurl/index.js:35:19
      2    0.0%    0.4%  LazyCompile: *normalizeParseOptions /app/node_modules/qs/lib/parse.js:189:59
      2    0.0%    0.4%  LazyCompile: *matchKnownFields _http_incoming.js:158:26
      2    0.0%    0.4%  LazyCompile: *getMapPrefixes /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:56:25
      2    0.0%    0.4%  LazyCompile: *flow _stream_readable.js:982:14
      2    0.0%    0.4%  LazyCompile: *end _http_outgoing.js:744:45
      2    0.0%    0.4%  LazyCompile: *emitDestroyScript internal/async_hooks.js:435:27
      2    0.0%    0.4%  LazyCompile: *clearBuffer _stream_writable.js:481:21
      2    0.0%    0.4%  LazyCompile: *Writable.write _stream_writable.js:258:36
      2    0.0%    0.4%  LazyCompile: *Stream internal/streams/legacy.js:9:16
      2    0.0%    0.4%  LazyCompile: *Socket._destroy net.js:650:37
      2    0.0%    0.4%  LazyCompile: *Readable _stream_readable.js:181:18
      2    0.0%    0.4%  LazyCompile: *EventEmitter events.js:64:22
      2    0.0%    0.4%  LazyCompile: *<anonymous> _http_outgoing.js:521:45
      1    0.0%    0.2%  RegExp: (?:[^\x21\x25\x26-\x3B\x3D\x3F-\x5B\x5D\x5F\x61-\x7A\x7E]|%(?:[^0-9A-Fa-f]|[0-9A-Fa-f][^0-9A-Fa-f]|$))+
      1    0.0%    0.2%  LazyCompile: *tryReadStart net.js:565:22
      1    0.0%    0.2%  LazyCompile: *socketOnClose _http_server.js:526:23
      1    0.0%    0.2%  LazyCompile: *socketListenerWrap _http_server.js:835:37
      1    0.0%    0.2%  LazyCompile: *resolve path.js:973:10
      1    0.0%    0.2%  LazyCompile: *percolateDown internal/priority_queue.js:49:16
      1    0.0%    0.2%  LazyCompile: *parserOnHeadersComplete _http_common.js:72:33
      1    0.0%    0.2%  LazyCompile: *onwrite _stream_writable.js:394:17
      1    0.0%    0.2%  LazyCompile: *module.exports /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:27:27
      1    0.0%    0.2%  LazyCompile: *finishMaybe _stream_writable.js:623:21
      1    0.0%    0.2%  LazyCompile: *fastparse /app/node_modules/parseurl/index.js:95:20
      1    0.0%    0.2%  LazyCompile: *emitReadable_ _stream_readable.js:558:23
      1    0.0%    0.2%  LazyCompile: *append internal/linkedlist.js:29:16
      1    0.0%    0.2%  LazyCompile: *_unrefTimer net.js:390:52
      1    0.0%    0.2%  LazyCompile: *_addHeaderLines _http_incoming.js:130:25
      1    0.0%    0.2%  LazyCompile: *_add /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/dogstatsd.js:54:8
      1    0.0%    0.2%  LazyCompile: *Socket.read net.js:617:33
      1    0.0%    0.2%  LazyCompile: *Readable.resume _stream_readable.js:937:37
      1    0.0%    0.2%  LazyCompile: *FastBuffer internal/buffer.js:945:1
      1    0.0%    0.2%  LazyCompile: *EventEmitter.init events.js:130:29

 [C++]:
   ticks  total  nonlib   name

 [Summary]:
   ticks  total  nonlib   name
    350    2.8%   78.7%  JavaScript
      0    0.0%    0.0%  C++
    154    1.2%   34.6%  GC
  12019   96.4%          Shared libraries
     95    0.8%          Unaccounted

 [C++ entry points]:
   ticks    cpp   total   name

 [Bottom up (heavy) profile]:
  Note: percentage shows a share of a particular caller in the total
  amount of its parent calls.
  Callers occupying less than 1.0% are not shown.

   ticks parent  name
   8223   66.0%  /lib/ld-musl-x86_64.so.1
    136    1.7%    /usr/local/bin/node
     20   14.7%      LazyCompile: *emitInitNative internal/async_hooks.js:139:24
      8   40.0%        /usr/local/bin/node
      5   62.5%          LazyCompile: ~Socket._final net.js:400:35
      5  100.0%            LazyCompile: ~callFinal _stream_writable.js:597:19
      2   25.0%          LazyCompile: ~connectionListenerInternal _http_server.js:407:36
      2  100.0%            LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      1   12.5%          LazyCompile: *connectionListenerInternal _http_server.js:407:36
      1  100.0%            LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      3   15.0%        LazyCompile: *Readable.resume _stream_readable.js:937:37
      3  100.0%          LazyCompile: ~_dump _http_incoming.js:291:49
      3  100.0%            LazyCompile: ~resOnFinish _http_server.js:678:21
      1    5.0%        LazyCompile: *Socket.resume net.js:608:35
      1  100.0%          LazyCompile: *Readable.on _stream_readable.js:850:33
      1  100.0%            LazyCompile: *connectionListenerInternal _http_server.js:407:36
     18   13.2%      LazyCompile: *_destroy /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:130:12
     18  100.0%        LazyCompile: *emitHook internal/async_hooks.js:170:18
     13    9.6%      LazyCompile: ~exports.floatFormatter /app/node_modules/hdr-histogram-js/formatters.js:15:35
     13  100.0%        Eval: ~<anonymous> /app/node_modules/hdr-histogram-js/HistogramLogWriter.js:1:1
     13  100.0%          LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
     13  100.0%            LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
     10    7.4%      LazyCompile: *emitInitScript internal/async_hooks.js:405:24
      4   40.0%        LazyCompile: ~initAsyncResource internal/timers.js:148:27
      2   50.0%          LazyCompile: ~Timeout internal/timers.js:158:17
      2  100.0%            LazyCompile: ~setUnrefTimeout internal/timers.js:362:25
      2   50.0%          LazyCompile: *_storeHeader _http_outgoing.js:352:22
      2  100.0%            LazyCompile: ~writeHead _http_server.js:244:19
      4   40.0%        LazyCompile: *Readable.read _stream_readable.js:383:35
      2   50.0%          LazyCompile: *flow _stream_readable.js:982:14
      2  100.0%            LazyCompile: ~emitReadable_ _stream_readable.js:558:23
      1   25.0%          LazyCompile: ~resume_ _stream_readable.js:958:17
      1  100.0%            LazyCompile: *processTicksAndRejections internal/process/task_queues.js:69:35
      1   25.0%          LazyCompile: ~Socket.read net.js:617:33
      1  100.0%            LazyCompile: ~onStreamRead internal/stream_base_commons.js:163:22
      2   20.0%        LazyCompile: *readableAddChunk _stream_readable.js:225:26
      2  100.0%          LazyCompile: ~Readable.push _stream_readable.js:216:35
      2  100.0%            LazyCompile: ~parserOnMessageComplete _http_common.js:136:33
     10    7.4%      LazyCompile: *emitHook internal/async_hooks.js:170:18
      9    6.6%      /usr/local/bin/node
      2   22.2%        LazyCompile: ~readPackage internal/modules/cjs/loader.js:251:21
      2  100.0%          LazyCompile: ~readPackageScope internal/modules/cjs/loader.js:285:26
      2  100.0%            LazyCompile: ~trySelf internal/modules/cjs/loader.js:402:17
      1   11.1%        LazyCompile: ~utcDate internal/http.js:18:17
      1  100.0%          LazyCompile: ~_storeHeader _http_outgoing.js:352:22
      1  100.0%            LazyCompile: ~writeHead _http_server.js:244:19
      1   11.1%        LazyCompile: ~getOwn internal/bootstrap/loaders.js:148:16
      1  100.0%          LazyCompile: ~syncExports internal/bootstrap/loaders.js:251:14
      1  100.0%            LazyCompile: ~<anonymous> internal/bootstrap/loaders.js:237:15
      1   11.1%        LazyCompile: ~escapeHtml /app/node_modules/escape-html/index.js:33:20
      1  100.0%          LazyCompile: ~createHtmlDocument /app/node_modules/finalhandler/index.js:43:29
      1  100.0%            LazyCompile: ~write /app/node_modules/finalhandler/index.js:273:18
      1   11.1%        LazyCompile: ~count /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:116:11
      1  100.0%          LazyCompile: ~increment /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:139:15
      1  100.0%            LazyCompile: ~_init /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:101:9
      1   11.1%        LazyCompile: ~Comparator.parse /app/node_modules/semver/semver.js:749:39
      1  100.0%          LazyCompile: ~Comparator /app/node_modules/semver/semver.js:714:21
      1  100.0%            LazyCompile: ~<anonymous> /app/node_modules/semver/semver.js:924:26
      1   11.1%        LazyCompile: ~<anonymous> /app/node_modules/hosted-git-info/index.js:45:52
      1  100.0%          /usr/local/bin/node
      1  100.0%            LazyCompile: ~fromUrl /app/node_modules/hosted-git-info/index.js:38:18
      1   11.1%        LazyCompile: *FastBuffer internal/buffer.js:945:1
      1  100.0%          LazyCompile: ~createUnsafeBuffer buffer.js:147:28
      1  100.0%            LazyCompile: ~createPool buffer.js:156:20
      5    3.7%      LazyCompile: *_storeHeader _http_outgoing.js:352:22
      3   60.0%        LazyCompile: ~writeHead _http_server.js:244:19
      2   66.7%          LazyCompile: *end _http_outgoing.js:744:45
      2  100.0%            LazyCompile: ~ok /app/src/index.js:38:12
      1   33.3%          LazyCompile: ~_implicitHeader _http_server.js:239:68
      1  100.0%            LazyCompile: ~write_ _http_outgoing.js:653:16
      2   40.0%        LazyCompile: *writeHead _http_server.js:244:19
      2  100.0%          LazyCompile: *end _http_outgoing.js:744:45
      1   50.0%            LazyCompile: ~ok /app/src/index.js:38:12
      1   50.0%            LazyCompile: *ok /app/src/index.js:38:12
      3    2.2%      LazyCompile: ~cache internal/http.js:23:15
      3  100.0%        LazyCompile: ~utcDate internal/http.js:18:17
      3  100.0%          LazyCompile: ~_storeHeader _http_outgoing.js:352:22
      3  100.0%            LazyCompile: ~writeHead _http_server.js:244:19
      3    2.2%      LazyCompile: ~Module._findPath internal/modules/cjs/loader.js:613:28
      2   66.7%        LazyCompile: ~Module._resolveFilename internal/modules/cjs/loader.js:964:35
      2  100.0%          LazyCompile: ~Module._load internal/modules/cjs/loader.js:877:24
      2  100.0%            LazyCompile: ~Module.require internal/modules/cjs/loader.js:1081:36
      1   33.3%        LazyCompile: ~resolveMainPath internal/modules/run_main.js:8:25
      1  100.0%          LazyCompile: ~executeUserEntryPoint internal/modules/run_main.js:64:31
      1  100.0%            Eval: ~<anonymous> internal/main/run_main_module.js:1:1
      2    1.5%      LazyCompile: ~processTimers internal/timers.js:477:25
      2    1.5%      LazyCompile: ~onceWrapper events.js:416:21
      2  100.0%        LazyCompile: *emit events.js:263:44
      2  100.0%          LazyCompile: ~finish _stream_writable.js:639:16
      2  100.0%            LazyCompile: ~finishMaybe _stream_writable.js:623:21
      2    1.5%      LazyCompile: ~emit events.js:263:44
      1   50.0%        LazyCompile: ~endReadableNT _stream_readable.js:1217:23
      1  100.0%          LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
      1   50.0%        LazyCompile: ~emitListeningNT net.js:1344:25
      1  100.0%          LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
      2    1.5%      LazyCompile: *writeUInt16 /app/node_modules/dd-trace/packages/dd-trace/src/encode/util.js:11:22
      2  100.0%        LazyCompile: ~getArrayPrefixes /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:39:27
      2  100.0%          Eval: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:1:1
      2  100.0%            LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
      2    1.5%      LazyCompile: *getMapPrefixes /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:56:25
      2  100.0%        Eval: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/encode/tokens.js:1:1
      2  100.0%          LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
      2  100.0%            LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
      2    1.5%      LazyCompile: *count /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:116:11
      1   50.0%        LazyCompile: ~increment /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:139:15
      1  100.0%          LazyCompile: ~_init /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:101:9
      1  100.0%            LazyCompile: ~emitInitNative internal/async_hooks.js:139:24
      1   50.0%        LazyCompile: ~decrement /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:143:15
      1  100.0%          LazyCompile: ~_destroy /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:130:12
      1  100.0%            LazyCompile: *emitHook internal/async_hooks.js:170:18
      2    1.5%      LazyCompile: *connectionListenerInternal _http_server.js:407:36
      1   50.0%        LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      1  100.0%          LazyCompile: ~connectionListener _http_server.js:401:28
      1  100.0%            LazyCompile: *emit events.js:263:44
      1   50.0%        LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      1  100.0%          LazyCompile: ~connectionListener _http_server.js:401:28
      1  100.0%            LazyCompile: *emit events.js:263:44

   3758   30.2%  /usr/local/bin/node
   1349   35.9%    /usr/local/bin/node
    115    8.5%      LazyCompile: ~writevGeneric internal/stream_base_commons.js:116:23
    115  100.0%        LazyCompile: ~Socket._writeGeneric net.js:756:42
    115  100.0%          LazyCompile: ~Socket._writev net.js:788:36
    115  100.0%            LazyCompile: ~doWrite _stream_writable.js:367:17
     87    6.4%      LazyCompile: ~wrapSafe internal/modules/cjs/loader.js:1101:18
     87  100.0%        LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
     87  100.0%          LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
     87  100.0%            LazyCompile: ~Module.load internal/modules/cjs/loader.js:1037:33
     82    6.1%      LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
     72   87.8%        LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      9   12.5%          Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      4    5.6%          LazyCompile: ~setupPrepareStackTrace internal/bootstrap/node.js:250:32
      4  100.0%            Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      4    5.6%          Eval: ~<anonymous> stream.js:1:1
      4  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      4    5.6%          Eval: ~<anonymous> crypto.js:1:1
      4  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      3    4.2%          LazyCompile: ~setupBuffer internal/bootstrap/node.js:298:21
      3  100.0%            Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      3    4.2%          Eval: ~<anonymous> tls.js:1:1
      3  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      3    4.2%          Eval: ~<anonymous> internal/url.js:1:1
      3  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      3    4.2%          Eval: ~<anonymous> http.js:1:1
      3  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      3    4.2%          Eval: ~<anonymous> events.js:1:1
      3  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2    2.8%          LazyCompile: ~initializeCJSLoader internal/bootstrap/pre_execution.js:399:29
      2  100.0%            LazyCompile: ~prepareMainThreadExecution internal/bootstrap/pre_execution.js:14:36
      2    2.8%          Eval: ~<anonymous> net.js:1:1
      2  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2    2.8%          Eval: ~<anonymous> internal/source_map/source_map_cache.js:1:1
      2  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2    2.8%          Eval: ~<anonymous> internal/process/esm_loader.js:1:1
      2  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2    2.8%          Eval: ~<anonymous> internal/modules/cjs/loader.js:1:1
      2  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2    2.8%          Eval: ~<anonymous> internal/console/global.js:1:1
      2  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2    2.8%          Eval: ~<anonymous> internal/cluster/master.js:1:1
      2  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2    2.8%          Eval: ~<anonymous> fs.js:1:1
      2  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2    2.8%          Eval: ~<anonymous> buffer.js:1:1
      2  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      2    2.8%          Eval: ~<anonymous> _http_agent.js:1:1
      2  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          LazyCompile: ~setupProcessObject internal/bootstrap/node.js:269:28
      1  100.0%            Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      1    1.4%          LazyCompile: ~get fs.js:2073:8
      1  100.0%            /usr/local/bin/node
      1    1.4%          LazyCompile: ~get dns.js:324:8
      1  100.0%            /usr/local/bin/node
      1    1.4%          LazyCompile: ~createGlobalConsole internal/bootstrap/node.js:315:29
      1  100.0%            Eval: ~<anonymous> internal/bootstrap/node.js:1:1
      1    1.4%          Eval: ~<anonymous> tty.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> internal/streams/lazy_transform.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> internal/process/task_queues.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> internal/modules/esm/loader.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> internal/modules/cjs/helpers.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> internal/main/run_main_module.js:1:1
      1    1.4%          Eval: ~<anonymous> internal/crypto/keygen.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> cluster.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> child_process.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> _tls_wrap.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> _http_common.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1    1.4%          Eval: ~<anonymous> _http_client.js:1:1
      1  100.0%            LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
     10   12.2%        LazyCompile: ~compileForPublicLoader internal/bootstrap/loaders.js:212:25
     10  100.0%          LazyCompile: ~loadNativeModule internal/modules/cjs/helpers.js:21:26
     10  100.0%            LazyCompile: ~Module._load internal/modules/cjs/loader.js:877:24
     81    6.0%      LazyCompile: ~doSend dgram.js:641:16
     50   61.7%        LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
     50  100.0%          LazyCompile: ~afterDns dgram.js:626:20
     47   94.0%            LazyCompile: *processTicksAndRejections internal/process/task_queues.js:69:35
      3    6.0%            LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
     23   28.4%        LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
     23  100.0%          LazyCompile: ~afterDns dgram.js:626:20
     23  100.0%            LazyCompile: *processTicksAndRejections internal/process/task_queues.js:69:35
      8    9.9%        LazyCompile: *afterDns dgram.js:626:20
      8  100.0%          LazyCompile: *processTicksAndRejections internal/process/task_queues.js:69:35
     71    5.3%      /usr/local/bin/node
     14   19.7%        LazyCompile: ~expressInit /app/node_modules/express/lib/middleware/init.js:29:30
      7   50.0%          LazyCompile: ~handle /app/node_modules/express/lib/router/layer.js:86:49
      7  100.0%            LazyCompile: ~trim_prefix /app/node_modules/express/lib/router/index.js:288:23
      7   50.0%          LazyCompile: *handle /app/node_modules/express/lib/router/layer.js:86:49
      7  100.0%            LazyCompile: ~trim_prefix /app/node_modules/express/lib/router/index.js:288:23
     11   15.5%        LazyCompile: *nextTick internal/process/task_queues.js:105:18
      4   36.4%          LazyCompile: ~resume _stream_readable.js:951:16
      4  100.0%            LazyCompile: ~Readable.resume _stream_readable.js:937:37
      4   36.4%          LazyCompile: ~emitReadable _stream_readable.js:547:22
      4  100.0%            LazyCompile: ~onEofChunk _stream_readable.js:517:20
      1    9.1%          LazyCompile: ~prefinish _stream_writable.js:610:19
      1  100.0%            LazyCompile: ~finishMaybe _stream_writable.js:623:21
      1    9.1%          LazyCompile: ~onwrite _stream_writable.js:394:17
      1  100.0%            LazyCompile: ~afterWriteDispatched internal/stream_base_commons.js:149:30
      1    9.1%          LazyCompile: ~lookup dns.js:92:16
      1  100.0%            LazyCompile: *Socket.send dgram.js:548:33
      9   12.7%        LazyCompile: *emitInitNative internal/async_hooks.js:139:24
      5   55.6%          LazyCompile: *Readable.resume _stream_readable.js:937:37
      5  100.0%            LazyCompile: ~_dump _http_incoming.js:291:49
      2   22.2%          /usr/local/bin/node
      2  100.0%            LazyCompile: ~Socket._final net.js:400:35
      1   11.1%          LazyCompile: ~emitInitScript internal/async_hooks.js:405:24
      1  100.0%            LazyCompile: ~initAsyncResource internal/timers.js:148:27
      1   11.1%          LazyCompile: *endReadable _stream_readable.js:1207:21
      1  100.0%            LazyCompile: ~Readable.read _stream_readable.js:383:35
      8   11.3%        LazyCompile: *_destroy /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:130:12
      8  100.0%          LazyCompile: *emitHook internal/async_hooks.js:170:18
      7    9.9%        LazyCompile: *emitInitScript internal/async_hooks.js:405:24
      6   85.7%          LazyCompile: *Readable.read _stream_readable.js:383:35
      3   50.0%            LazyCompile: *flow _stream_readable.js:982:14
      3   50.0%            LazyCompile: *emitReadable_ _stream_readable.js:558:23
      1   14.3%          LazyCompile: *readableAddChunk _stream_readable.js:225:26
      1  100.0%            LazyCompile: ~Readable.push _stream_readable.js:216:35
      2    2.8%        LazyCompile: ~onParserExecuteCommon _http_server.js:613:31
      2  100.0%          LazyCompile: ~onParserExecute _http_server.js:576:25
      2    2.8%        LazyCompile: ~count /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:116:11
      1   50.0%          LazyCompile: ~increment /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:139:15
      1  100.0%            LazyCompile: ~_init /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:101:9
      1   50.0%          LazyCompile: ~decrement /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:143:15
      1  100.0%            LazyCompile: ~_destroy /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:130:12
      2    2.8%        Eval: ~<anonymous> /app/node_modules/debug/src/node.js:1:1
      2  100.0%          LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
      2  100.0%            LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
      1    1.4%        LazyCompile: ~trimLeft /app/node_modules/url-parse/index.js:16:18
      1  100.0%          LazyCompile: ~extractProtocol /app/node_modules/url-parse/index.js:116:25
      1  100.0%            LazyCompile: ~Url /app/node_modules/url-parse/index.js:177:13
      1    1.4%        LazyCompile: ~replaceXRange /app/node_modules/semver/semver.js:1088:24
      1  100.0%          LazyCompile: ~<anonymous> /app/node_modules/semver/semver.js:1083:41
      1  100.0%            /usr/local/bin/node
      1    1.4%        LazyCompile: ~readPackage internal/modules/cjs/loader.js:251:21
      1  100.0%          LazyCompile: ~readPackageScope internal/modules/cjs/loader.js:285:26
      1  100.0%            LazyCompile: ~trySelf internal/modules/cjs/loader.js:402:17
      1    1.4%        LazyCompile: ~parseQueryStringValues /app/node_modules/qs/lib/parse.js:41:50
      1  100.0%          LazyCompile: ~module.exports /app/node_modules/qs/lib/parse.js:222:27
      1  100.0%            LazyCompile: ~parseExtendedQueryString /app/node_modules/express/lib/utils.js:291:34
      1    1.4%        LazyCompile: ~parseGitUrl /app/node_modules/hosted-git-info/index.js:107:22
      1  100.0%          LazyCompile: ~fromUrl /app/node_modules/hosted-git-info/index.js:38:18
      1  100.0%            LazyCompile: ~module.exports.fromUrl /app/node_modules/hosted-git-info/index.js:27:35
      1    1.4%        LazyCompile: ~merge /app/node_modules/qs/lib/utils.js:45:27
      1  100.0%          LazyCompile: ~module.exports /app/node_modules/qs/lib/parse.js:222:27
      1  100.0%            LazyCompile: ~parseExtendedQueryString /app/node_modules/express/lib/utils.js:291:34
      1    1.4%        LazyCompile: ~getOwn internal/bootstrap/loaders.js:148:16
      1  100.0%          LazyCompile: ~syncExports internal/bootstrap/loaders.js:251:14
      1  100.0%            LazyCompile: ~<anonymous> internal/bootstrap/loaders.js:237:15
      1    1.4%        LazyCompile: ~extendStatics /app/node_modules/hdr-histogram-js/RecordedValuesIterator.js:10:34
      1  100.0%          LazyCompile: ~__extends /app/node_modules/hdr-histogram-js/RecordedValuesIterator.js:16:21
      1  100.0%            Eval: ~<anonymous> /app/node_modules/hdr-histogram-js/RecordedValuesIterator.js:29:54
      1    1.4%        LazyCompile: ~escapeHtml /app/node_modules/escape-html/index.js:33:20
      1  100.0%          LazyCompile: ~createHtmlDocument /app/node_modules/finalhandler/index.js:43:29
      1  100.0%            LazyCompile: ~write /app/node_modules/finalhandler/index.js:273:18
      1    1.4%        LazyCompile: ~encodeUrl /app/node_modules/encodeurl/index.js:56:20
      1  100.0%          LazyCompile: ~<anonymous> /app/node_modules/finalhandler/index.js:86:19
      1  100.0%            LazyCompile: ~<anonymous> /app/node_modules/express/lib/router/index.js:629:19
      1    1.4%        LazyCompile: ~_init /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:101:9
      1  100.0%          LazyCompile: ~emitInitNative internal/async_hooks.js:139:24
      1  100.0%            LazyCompile: ~emitInitScript internal/async_hooks.js:405:24
      1    1.4%        LazyCompile: ~Module._findPath internal/modules/cjs/loader.js:613:28
      1  100.0%          LazyCompile: ~Module._resolveFilename internal/modules/cjs/loader.js:964:35
      1  100.0%            LazyCompile: ~Module._load internal/modules/cjs/loader.js:877:24
      1    1.4%        LazyCompile: *FastBuffer internal/buffer.js:945:1
      1  100.0%          LazyCompile: ~createUnsafeBuffer buffer.js:147:28
      1  100.0%            LazyCompile: ~createPool buffer.js:156:20
      1    1.4%        Eval: ~<anonymous> _stream_passthrough.js:1:1
      1  100.0%          LazyCompile: ~compileForInternalLoader internal/bootstrap/loaders.js:263:27
      1  100.0%            LazyCompile: ~nativeModuleRequire internal/bootstrap/loaders.js:296:29
      1    1.4%        Eval: ~<anonymous> /app/node_modules/spdx-correct/index.js:1:1
      1  100.0%          LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
      1  100.0%            LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
      1    1.4%        Eval: ~<anonymous> /app/node_modules/express/lib/express.js:1:1
      1  100.0%          LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
      1  100.0%            LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
     51    3.8%      LazyCompile: ~Socket._final net.js:400:35
     51  100.0%        LazyCompile: ~callFinal _stream_writable.js:597:19
     50   98.0%          LazyCompile: *processTicksAndRejections internal/process/task_queues.js:69:35
      1    2.0%          LazyCompile: ~processTicksAndRejections internal/process/task_queues.js:69:35
     48    3.6%      LazyCompile: ~Socket._destroy net.js:650:37
     48  100.0%        LazyCompile: ~destroy internal/streams/destroy.js:5:17
     44   91.7%          LazyCompile: ~onReadableStreamEnd net.js:627:29
     27   61.4%            LazyCompile: *emit events.js:263:44
     17   38.6%            LazyCompile: ~emit events.js:263:44
      4    8.3%          LazyCompile: ~onceWrapper events.js:416:21
      4  100.0%            LazyCompile: *emit events.js:263:44
     46    3.4%      LazyCompile: *_destroy /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:130:12
     46  100.0%        LazyCompile: *emitHook internal/async_hooks.js:170:18
     37    2.7%      LazyCompile: *emitInitNative internal/async_hooks.js:139:24
     10   27.0%        /usr/local/bin/node
      5   50.0%          LazyCompile: *connectionListenerInternal _http_server.js:407:36
      3   60.0%            LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      2   40.0%            LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      3   30.0%          LazyCompile: ~connectionListenerInternal _http_server.js:407:36
      3  100.0%            LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      2   20.0%          LazyCompile: ~Socket._final net.js:400:35
      2  100.0%            LazyCompile: ~callFinal _stream_writable.js:597:19
      3    8.1%        LazyCompile: ~emitInitScript internal/async_hooks.js:405:24
      2   66.7%          LazyCompile: *Readable.read _stream_readable.js:383:35
      2  100.0%            LazyCompile: ~flow _stream_readable.js:982:14
      1   33.3%          LazyCompile: ~initAsyncResource internal/timers.js:148:27
      1  100.0%            LazyCompile: ~Immediate timers.js:208:14
      3    8.1%        LazyCompile: *Socket.resume net.js:608:35
      3  100.0%          LazyCompile: *Readable.on _stream_readable.js:850:33
      3  100.0%            LazyCompile: *connectionListenerInternal _http_server.js:407:36
      2    5.4%        LazyCompile: *Readable.resume _stream_readable.js:937:37
      1   50.0%          LazyCompile: ~_dump _http_incoming.js:291:49
      1  100.0%            LazyCompile: ~resOnFinish _http_server.js:678:21
      1   50.0%          LazyCompile: ~Socket.resume net.js:608:35
      1  100.0%            LazyCompile: *Readable.on _stream_readable.js:850:33
      1    2.7%        LazyCompile: *onwrite _stream_writable.js:394:17
      1  100.0%          LazyCompile: *clearBuffer _stream_writable.js:481:21
      1  100.0%            LazyCompile: ~Writable.uncork _stream_writable.js:310:37
     36    2.7%      LazyCompile: *nextTick internal/process/task_queues.js:105:18
     11   30.6%        LazyCompile: ~resume _stream_readable.js:951:16
     11  100.0%          LazyCompile: ~Readable.resume _stream_readable.js:937:37
      9   81.8%            LazyCompile: ~Socket.resume net.js:608:35
      2   18.2%            LazyCompile: ~_dump _http_incoming.js:291:49
     10   27.8%        LazyCompile: ~onwrite _stream_writable.js:394:17
      8   80.0%          LazyCompile: ~afterWriteDispatched internal/stream_base_commons.js:149:30
      8  100.0%            LazyCompile: ~writevGeneric internal/stream_base_commons.js:116:23
      2   20.0%          LazyCompile: *clearBuffer _stream_writable.js:481:21
      2  100.0%            LazyCompile: *end _http_outgoing.js:744:45
      6   16.7%        LazyCompile: ~resOnFinish _http_server.js:678:21
      5   83.3%          LazyCompile: *emit events.js:263:44
      5  100.0%            LazyCompile: ~onFinish _http_outgoing.js:739:18
      1   16.7%          LazyCompile: ~emit events.js:263:44
      1  100.0%            LazyCompile: ~onFinish _http_outgoing.js:739:18
      2    5.6%        LazyCompile: ~lookup dns.js:92:16
      2  100.0%          LazyCompile: ~lookup4 internal/dgram.js:17:17
      2  100.0%            LazyCompile: ~Socket.send dgram.js:548:33
      2    5.6%        LazyCompile: ~endReadable _stream_readable.js:1207:21
      2  100.0%          LazyCompile: ~Readable.read _stream_readable.js:383:35
      1   50.0%            LazyCompile: ~flow _stream_readable.js:982:14
      1   50.0%            LazyCompile: *Socket.read net.js:617:33
      2    5.6%        LazyCompile: ~emitReadable _stream_readable.js:547:22
      2  100.0%          LazyCompile: ~onEofChunk _stream_readable.js:517:20
      2  100.0%            LazyCompile: ~readableAddChunk _stream_readable.js:225:26
      1    2.8%        LazyCompile: ~<anonymous> internal/streams/destroy.js:36:30
      1  100.0%          LazyCompile: ~Socket._destroy net.js:650:37
      1  100.0%            LazyCompile: ~destroy internal/streams/destroy.js:5:17
      1    2.8%        LazyCompile: *finishMaybe _stream_writable.js:623:21
      1  100.0%          LazyCompile: ~Writable.end _stream_writable.js:542:34
      1  100.0%            LazyCompile: ~Socket.end net.js:587:32
      1    2.8%        LazyCompile: *destroy internal/streams/destroy.js:5:17
      1  100.0%          LazyCompile: ~onReadableStreamEnd net.js:627:29
      1  100.0%            LazyCompile: *endReadableNT _stream_readable.js:1217:23
     32    2.4%      LazyCompile: *_storeHeader _http_outgoing.js:352:22
     21   65.6%        LazyCompile: ~writeHead _http_server.js:244:19
     14   66.7%          LazyCompile: *end _http_outgoing.js:744:45
     14  100.0%            LazyCompile: ~ok /app/src/index.js:38:12
      7   33.3%          LazyCompile: ~_implicitHeader _http_server.js:239:68
      7  100.0%            LazyCompile: ~write_ _http_outgoing.js:653:16
     11   34.4%        LazyCompile: *writeHead _http_server.js:244:19
     11  100.0%          LazyCompile: *end _http_outgoing.js:744:45
      8   72.7%            LazyCompile: *ok /app/src/index.js:38:12
      3   27.3%            LazyCompile: ~ok /app/src/index.js:38:12
     28    2.1%      LazyCompile: ~memoryUsage internal/process/per_thread.js:150:23
     28  100.0%        LazyCompile: ~captureMemoryUsage /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:178:29
     28  100.0%          LazyCompile: ~captureCommonMetrics /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:249:31
     28  100.0%            LazyCompile: ~<anonymous> /app/node_modules/dd-trace/packages/dd-trace/src/platform/node/metrics.js:60:32
     20    1.5%      LazyCompile: *Socket.resume net.js:608:35
     20  100.0%        LazyCompile: *Readable.on _stream_readable.js:850:33
     20  100.0%          LazyCompile: *connectionListenerInternal _http_server.js:407:36
     12   60.0%            LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      8   40.0%            LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
     18    1.3%      LazyCompile: ~exports.floatFormatter /app/node_modules/hdr-histogram-js/formatters.js:15:35
     18  100.0%        Eval: ~<anonymous> /app/node_modules/hdr-histogram-js/HistogramLogWriter.js:1:1
     18  100.0%          LazyCompile: ~Module._compile internal/modules/cjs/loader.js:1154:37
     18  100.0%            LazyCompile: ~Module._extensions..js internal/modules/cjs/loader.js:1209:37
     16    1.2%      LazyCompile: ~tryReadStart net.js:565:22
     16  100.0%        LazyCompile: ~Socket._read net.js:575:34
     12   75.0%          LazyCompile: *Readable.read _stream_readable.js:383:35
     11   91.7%            LazyCompile: *Socket net.js:264:16
      1    8.3%            LazyCompile: ~Socket.read net.js:617:33
      4   25.0%          LazyCompile: ~Readable.read _stream_readable.js:383:35
      2   50.0%            LazyCompile: ~Socket.read net.js:617:33
      2   50.0%            LazyCompile: *Socket net.js:264:16
     16    1.2%      LazyCompile: *Readable.read _stream_readable.js:383:35
      7   43.8%        LazyCompile: *flow _stream_readable.js:982:14
      6   85.7%          LazyCompile: ~emitReadable_ _stream_readable.js:558:23
      3   50.0%            LazyCompile: ~onEofChunk _stream_readable.js:517:20
      3   50.0%            LazyCompile: *processTicksAndRejections internal/process/task_queues.js:69:35
      1   14.3%          LazyCompile: ~resume_ _stream_readable.js:958:17
      1  100.0%            LazyCompile: *processTicksAndRejections internal/process/task_queues.js:69:35
      4   25.0%        LazyCompile: ~resume_ _stream_readable.js:958:17
      4  100.0%          LazyCompile: *processTicksAndRejections internal/process/task_queues.js:69:35
      2   12.5%        LazyCompile: ~flow _stream_readable.js:982:14
      2  100.0%          LazyCompile: ~emitReadable_ _stream_readable.js:558:23
      2  100.0%            LazyCompile: *processTicksAndRejections internal/process/task_queues.js:69:35
      2   12.5%        LazyCompile: ~Socket.read net.js:617:33
      2  100.0%          LazyCompile: ~onStreamRead internal/stream_base_commons.js:163:22
      1    6.3%        LazyCompile: *resume_ _stream_readable.js:958:17
      1  100.0%          LazyCompile: *processTicksAndRejections internal/process/task_queues.js:69:35
     15    1.1%      LazyCompile: *Readable.resume _stream_readable.js:937:37
     12   80.0%        LazyCompile: ~Socket.resume net.js:608:35
     12  100.0%          LazyCompile: *Readable.on _stream_readable.js:850:33
     12  100.0%            LazyCompile: *connectionListenerInternal _http_server.js:407:36
      3   20.0%        LazyCompile: ~_dump _http_incoming.js:291:49
      3  100.0%          LazyCompile: ~resOnFinish _http_server.js:678:21
      3  100.0%            LazyCompile: *emit events.js:263:44
     14    1.0%      LazyCompile: *Readable.on _stream_readable.js:850:33
     13   92.9%        LazyCompile: *connectionListenerInternal _http_server.js:407:36
      8   61.5%          LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      8  100.0%            LazyCompile: ~connectionListener _http_server.js:401:28
      5   38.5%          LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      5  100.0%            LazyCompile: ~connectionListener _http_server.js:401:28
      1    7.1%        LazyCompile: ~connectionListenerInternal _http_server.js:407:36
      1  100.0%          LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      1  100.0%            LazyCompile: ~connectionListener _http_server.js:401:28
     55    1.5%    LazyCompile: ~onconnection net.js:1526:22
     54    1.4%    LazyCompile: *_destroy /app/node_modules/dd-trace/packages/dd-trace/src/scope/async_hooks.js:130:12
     54  100.0%      LazyCompile: *emitHook internal/async_hooks.js:170:18
     48    1.3%    LazyCompile: *emitInitNative internal/async_hooks.js:139:24
      7   14.6%      /usr/local/bin/node
      4   57.1%        LazyCompile: *connectionListenerInternal _http_server.js:407:36
      2   50.0%          LazyCompile: ~defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      2  100.0%            LazyCompile: ~connectionListener _http_server.js:401:28
      2   50.0%          LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      2  100.0%            LazyCompile: ~connectionListener _http_server.js:401:28
      3   42.9%        LazyCompile: ~Socket._final net.js:400:35
      3  100.0%          LazyCompile: ~callFinal _stream_writable.js:597:19
      3  100.0%            LazyCompile: *processTicksAndRejections internal/process/task_queues.js:69:35
      4    8.3%      LazyCompile: *endReadable _stream_readable.js:1207:21
      4  100.0%        LazyCompile: ~Readable.read _stream_readable.js:383:35
      2   50.0%          LazyCompile: ~resume_ _stream_readable.js:958:17
      2  100.0%            LazyCompile: *processTicksAndRejections internal/process/task_queues.js:69:35
      2   50.0%          LazyCompile: ~flow _stream_readable.js:982:14
      2  100.0%            LazyCompile: ~resume_ _stream_readable.js:958:17
      3    6.3%      LazyCompile: *Socket.resume net.js:608:35
      3  100.0%        LazyCompile: *Readable.on _stream_readable.js:850:33
      3  100.0%          LazyCompile: *connectionListenerInternal _http_server.js:407:36
      3  100.0%            LazyCompile: *defaultTriggerAsyncIdScope internal/async_hooks.js:369:36
      2    4.2%      LazyCompile: ~emitInitScript internal/async_hooks.js:405:24
      1   50.0%        LazyCompile: ~nextTick internal/process/task_queues.js:105:18
      1  100.0%          LazyCompile: ~endReadable _stream_readable.js:1207:21
      1  100.0%            LazyCompile: ~Readable.read _stream_readable.js:383:35
      1   50.0%        LazyCompile: ~initAsyncResource internal/timers.js:148:27
      1  100.0%          LazyCompile: ~Timeout internal/timers.js:158:17
      1  100.0%            LazyCompile: ~setUnrefTimeout internal/timers.js:362:25
      2    4.2%      LazyCompile: *Readable.resume _stream_readable.js:937:37
      1   50.0%        LazyCompile: ~_dump _http_incoming.js:291:49
      1  100.0%          LazyCompile: ~resOnFinish _http_server.js:678:21
      1  100.0%            LazyCompile: *emit events.js:263:44
      1   50.0%        LazyCompile: ~Socket.resume net.js:608:35
      1  100.0%          LazyCompile: *Readable.on _stream_readable.js:850:33
      1  100.0%            LazyCompile: *connectionListenerInternal _http_server.js:407:36
     43    1.1%    LazyCompile: *emitHook internal/async_hooks.js:170:18
      3    7.0%      LazyCompile: *processTicksAndRejections internal/process/task_queues.js:69:35
      2    4.7%      LazyCompile: *listOnTimeout internal/timers.js:497:25
      1   50.0%        LazyCompile: ~processTimers internal/timers.js:477:25
      1    2.3%      LazyCompile: ~emitBeforeScript internal/async_hooks.js:419:26
      1  100.0%        LazyCompile: ~listOnTimeout internal/timers.js:497:25
      1  100.0%          LazyCompile: ~processTimers internal/timers.js:477:25
     38    1.0%    LazyCompile: ~processTimers internal/timers.js:477:25```

kaievns commented 4 years ago

overall, i see exactly the same pattern on an empty application as i do with an actual application with our codebase. here is the node runtime metrics, and they match exactly to the kubernetes pod CPU utilisation pattern.

kaievns commented 4 years ago

after extensive pocking at it, i can tell that enabling any of the following plugins sends it haywire:


  // tracer.use('http', false);
  // tracer.use('https', false);
  // tracer.use('http2', false);
  // tracer.use('net', false);

  // tracer.use('connect', false);
  // tracer.use('express', false);```

this look consistently like a problem with the networking stack tracing.

any thoughts, ideas, are more than appreciated

kaievns commented 4 years ago

i can provide you with access to the docker image if that will help

rochdev commented 4 years ago

i can provide you with access to the docker image if that will help

That would definitely help. Is this something I could run on my end?

rochdev commented 4 years ago

The last profiles look like they are from an idle app. For an idle app, it's expected that the tracer will use a lot more CPU since it actually uses it. Do you have profiles of an app getting traffic?

kaievns commented 4 years ago

Well, my problem is not that it uses some CPU, that is expected. my problem is that it starts to eat a lot more CPU, when I enable network plugins. like 5% of a CPU (or 10% if the async patching is enabled) in idle state that is a lot, comparing to sub 1% with all the same tracing/runtime metrics enabled, but network plugins disabled. even when it is not receiving any significant network traffic.

I don't know what's going on on the inside of the npm package, it looks like those plugins monkey patch code. But, I do know that both, node runtime metrics and kubes CUP utilisation spike significantly for some reason when i enable network plugins. I need to instrument dozens of microservises scaled up horizontally, and if 10-20 pods consume a whole CPU in idle state, well, that's just not going to work.

i've published the docker image over here https://hub.docker.com/repository/docker/shortlyster/dd-test, as i said it is pretty vanilla app. express and dd-trace are literally the only deps in there at this point. you can launch it with docker run shortlyster/dd-test. I can't really trace CPU utilisation in localhost, but i tried to switch things on and off in two different kubes clusters that we have, and saw exactly the same behaviour i described above

would be really good to get to the bottom of this soon. i've been paying for the service for two weeks now and not getting a whole lot of working solution back at the moment. it's been a bit of an uphill battle all those days to be honest. so, i'd appreciate any help you can throw our way. thanks!

rochdev commented 4 years ago

I'll have to look into it and see what we could do to reduce the overhead. In the meantime, I would recommend trying to filter out the health check to avoid sending unnecessary traces since it looks like most of the overhead comes from that.

For example, if the health check is at /health then the configuration would look like this:

tracer.use('express', {
  blacklist: ['/health']
})

This will prevent these traces from being sent, thus saving on the encoding and the transport, which should have a positive impact. Turning off runtime metrics would help as well since these will report regardless of traffic, but of course this should only be done if you feel they are not needed for a given service.

kaievns commented 4 years ago

i don't know how i feel about blacklisting healthchecks, all it's going to do is obfuscate the problem. that 500% overhead will just be baked into normal requests and be invisible. what's the point of having monitoring tooling that doesn't work properly? i'm not looking to hide the problem, i'm looking to solve it

runtime metrics don't seem to have any visible impact on CPU consumption. if i disable plugins, it is still there and happily reports the data as usual without causing any problems

kaievns commented 4 years ago

okay, in the interest of science, i added the healthchecks into the blacklist and re-enabled plugins. the CPU usage had spiked back. also, i don't think that's express problem, the usage spikes even if i enable the net plugin alone without anything else. in comparison, if i enable just fs plugin, no spike happens.

rochdev commented 4 years ago

i don't know how i feel about blacklisting healthchecks, all it's going to do is obfuscate the problem. that 500% overhead will just be baked into normal requests and be invisible. what's the point of having monitoring tooling that doesn't work properly? i'm not looking to hide the problem, i'm looking to solve it

Actually, the more the service itself is doing the less the overhead of the tracer will be apparent. An app that does nothing is the worst case scenario.

okay, in the interest of science, i added the healthchecks into the blacklist and re-enabled plugins. the CPU usage had spiked back. also, i don't think that's express problem, the usage spikes even if i enable the net plugin alone without anything else. in comparison, if i enable just fs plugin, no spike happens.

Thank you for trying this. It's good to know that net also causes issues since that should definitely not be the case for an empty health check. I'll look into this with the Docker image you provided.

rochdev commented 4 years ago

Could you share your blacklisting config? I was able to resolve the overhead with the following config:

tracer.use('express', {
  blacklist: [
    '/_health/ready',
    '/_health/alive'
  ]
})

That will solve the overhead when idling, and as previously mentioned, the overhead will be much lower for actual requests since the app itself will be using the CPU, thus lowering the usage difference between the app and the tracer.

kaievns commented 4 years ago

i'm sorry, but that's not true. all blacklisting does it masks the problem in idle state. here, look at this graph, i've run our e2e suite 4 times. 2 times with the plugins or the left, and 2 times without the plugins on the right, do you see the difference?

i don't know how you came up with the idea that the actual usage somehow will be immune to the problem, but that is clearly not the case

kaievns commented 4 years ago

i've tried to run exactly the same tracing with opentelemetry + GCP, the honeycomb, and new relic. none of them show anything close to what i get with the dd-trace. frankly, i'm very disappointed just how much effort it is taking for me to make you even acknowledge the issue, let alone do something about it. i provided traces, graphs, tried all the options you asked, even got you a whole docker image for analysis. and in 3 weeks it got me exactly nowhere

this whole story with "can you blacklist the problem so that it wasn't visible?" is such a joke!

i need you to do better than this

rochdev commented 4 years ago

i don't know how you came up with the idea that the actual usage somehow will be immune to the problem, but that is clearly not the case

Sorry about the misunderstanding, somewhere along the way I got confused and started assuming that the issue only existed when the app is idle. Now it's clear to me with the latest graph that this is not the case.

Let's summarize what we know so far:

Using trackAsyncScope: false helped cut the overhead in half, so definitely keep that. Alternatively, if you use Node 14 you could switch to the new AsyncLocalStorage based scope manager that is overall much faster and doesn't need that option to be set. This is only available in dd-trace >=0.21.0 and can be enabled with scope: 'async_local_storage'.
Turning off spans didn't fix the issue. Did you still see a noticeable difference? Any numbers you can share? If it helped somewhat and there are any spans that you don't need, it might make sense to disable them anyway. From my understanding of your use case, it would look like this:
```
tracer.use('express', {
// disable express.middleware spans but keeps express.request
middleware: false 
})
tracer.use('dns', false)
tracer.use('net', false)
```
Filtering out health checks didn't solve the issue since it's not just when the app is idle. I would still recommend to do it anyway regardless of the performance issue since those traces are unnecessary and are just generating noise.

I tried replicating the issue on my end using a custom Express/Mongo app I built that generates traces similar to what I could find in your account with my support team. Since the Docker image you provided only included a health check, I wasn't sure if it was meant to test under load or only when idling. If it can be used to test under load as well, please let me know since running my tests on something closer to the real app would be ideal.

While I got a significant increase in CPU usage, it wasn't anywhere near the overhead you are seeing. Was this overhead using the same Docker image that you shared? If so, how was load being simulated for the test? Is there any of the above profiles that was captured under load, and if not, is that something you can share? If you used the Docker image this shouldn't be necessary since I should be able to use profiling on my end with it.

One thing to note also is that we are currently actively working on general performance improvements for the tracer which should help a lot, but that work won't be released for a while. If you are interested we can reach out when we release these enhancements if you want to try them. In the meantime I will do my best to provide a fix once I'm confident that I have a test case that is close enough to your app. I'm also actively trying to find the main bottleneck with the information I currently have.

I would definitely recommend to DM me on our public Slack since it will make the discussion a lot faster, especially given the big time difference between us. I'm easier to reach on Slack than Github between 7PM and 10PM, which is when most of our days overlap (9AM to 12PM in your timezone).

I'm really sorry for the experience you've had so far, but now that we're on the same page let's get to the bottom of this.

Alfarlost commented 4 years ago

@rochdev, @MadRabbit we noticed similar issue just after upgrading from 0.14.0 to 0.21.0 version. So downgrading to 0.14.0 version maybe a temporary solution for you @MadRabbit .

rochdev commented 4 years ago

@Alfarlost We added new integrations between these 2 versions, so it's possible that in your case it's caused by the additional instrumentation. Did you notice any new spans in your traces after upgrading?

We also changed how encoding is done in 0.20.2. Can you try with 0.20.1 which uses the old encoding logic? It's possible there was a performance regression in the new logic.

Alfarlost commented 4 years ago

@rochdev we figured out that the latest version that doesn't cause x10 cpu spike was 0.18.1. All later versions causes our kubernetes pods to consume x10 CPU.

rochdev commented 4 years ago

@Alfarlost Did you explicitly try 0.20.0 or 0.20.1? The encoding changes were added in 0.19.0 and were reverted in these 2 versions and re-applied in 0.20.2. If any of these 2 doesn't have the additional overhead for you then it means for sure the problem is the new encoder.

Also, are you using aws-sdk? The only change other than a few bug fixes and the encoding changes in 0.19.0 was adding the aws-sdk integration, so it has to be either the encoding changes or aws-sdk.

Alfarlost commented 4 years ago

@rochdev probably it's an aws-sdk causes this. Could we manually turn off span related to aws-sdk?

rochdev commented 4 years ago

@Alfarlost Yes it can be disabled in code using tracer.use('aws-sdk', false) or with the DD_TRACE_DISABLED_PLUGINS=aws-sdk environment variable.

mnahkies commented 4 years ago

We just experienced this (or similar) problem upgrading dd-trace from 0.18.1 to 0.23.3 - if I get time I'll try upgrading it to 0.20.1 as per above.

That project is not using the aws-sdk at all.

nodejs v12 LTS

mnahkies commented 4 years ago

Tried deploying with no k8 CPU limit today to avoid CFS throttling. The pod has gone from a baseline of ~5m -> ~25m-30m with spikes to ~200m with the same library configuration.

Same issue with dd-trace@0.20.1 unfortunately

rochdev commented 4 years ago

@mnahkies Just to confirm, the additional overhead is present in both 0.20.1 and 0.23.3, but not when using 0.18.1?

mnahkies commented 4 years ago

@rochdev correct - I haven't tried any other versions in between 0.18.1 and 0.20.1 to verify exactly when it regressed though

rochdev commented 4 years ago

@mnahkies It might be a regression with the cache layer that was introduced in the encoding before sending to the agent. We are in the process of rewriting this layer which should remove most of the overhead associated with the existing LRU. Hopefully this will address the regression. I will keep this issue posted when it's released.

millerick commented 4 years ago

Can we have some clarification on whether this is caused by a specific plugin that is problematic or if the issue is with encoding logic that is common between all plugins?

rochdev commented 4 years ago

@millerick From some of the above comments, it looks like the issue started in 0.19.0. The main 2 changes from that release were the addition of aws-sdk and a rewrite of the msgpack encoder used to encode traces. We haven't been able yet to get a definitive answer on which of these 2 changes started the issue since everyone in the thread so far were using aws-sdk.

Now that we have confirmation from someone who is not using aws-sdk, we can assume the issue is a regression with the encoder. We have just updated the caching logic of the encoder to be simpler and faster, and our theory so far is that the old cache caused the regression.

@mnahkies Can you try 0.26.0-beta.0 and see if the issue is fixed? If you can also update the agent, then I would recommend updating it to 7.22 which has a new endpoint that allows the tracer to be even more efficient with the new caching logic.

millerick commented 4 years ago

@mnahkies , I would love to get confirmation on whether or not this was fixed in 0.26.0

mnahkies commented 4 years ago

@millerick apologies - I was on holiday

Our cluster is running datadog/agent:7.22.0 for the agent side of things. Running a service with 0.26.0 doesn't appear to have changed anything, still consumes far more CPU than with the older version

rochdev commented 4 years ago

@mnahkies It looks like my assumption of the issue being the encoder cache may not actually be the case. It has to be the encoding logic itself then. Since we'll need a CPU profile and access to your account, can you reach out to me on our public Slack and/or contact support?

rochdev commented 3 years ago

We think we've identified the issue in the encoder, which has been rewritten completely in the past couple weeks to fix not only the CPU usage issue but also simplifying the logic a lot. There are already a few reports of the issue being resolved by other users, so we're confident that the issue is fixed at this point.

The fix is included in dd-trace 0.27, and we also did other performance improvements which could be beneficial to reduce the overhead even further. To get these additional improvements as well, Node should be updated to at least 12.19 or 14.5 since we rely on changes from these versions. The agent should also be at least version 7.23 which includes a new endpoint mentioned earlier in this thread, which can be used with the protocolVersion: '0.5' option on the tracer or the DD_TRACE_AGENT_PROTOCOL_VERSION=0.5 environment variable.

@MadRabbit Sorry it took so long to get to the bottom of this! The information we needed to figure it out was not showing clearly in the profiles since it was an issue with how v8 was not optimizing our code properly, so we ended up investigating the wrong bottlenecks that were actually unrelated. Please confirm if your issue is resolved with this new version.

kaievns commented 3 years ago

Hi Roch, thank you for the update. i'll give it a try at some point. do i understand this correctly that i need to specify the protocolVersion: '0.5' explicitly to make this work?

btw, most of the performance issues were gone for us after an upgrade to node 14.5 and disabling the asyncScope thing. i'll give the new version a go as well, always good to have less overheads

DataDog / dd-trace-js

Plugins consume too much CPU #969