dd-trace-js

dd-trace-js copied to clipboard

Expected behaviour

Express plugin to be in intergrations_loaded array

Actual behaviour

When using [email protected] you can see express in integrations_loaded and it modifies the span

DATADOG TRACER CONFIGURATION - {"date":"2022-06-27T17:19:29.503Z","os_name":"Linux","os_version":"5.4.0-120-generic","architecture":"x64","version":"2.6.0","lang":"nodejs","lang_version":"16.13.0","env":"REMOTE_DEV","service":"speero-backend","agent_url":"http://127.0.0.1:8126/","debug":false,"sample_rate":1,"sampling_rules":[],"tags":{"service":"speero-backend","env":"REMOTE_DEV","version":"5.1.2","runtime-id":"d8052cf0-489f-4d09-9aba-60d0c1adfca8"},"dd_version":"5.1.2","log_injection_enabled":true,"runtime_metrics_enabled":false,"profiling_enabled":false,"integrations_loaded":["fs","http2","[email protected]"],"appsec_enabled":false}

But when using [email protected] express isn't added to integrations_loaded array and span doesn't get modified

DATADOG TRACER CONFIGURATION - {"date":"2022-06-27T17:22:18.997Z","os_name":"Linux","os_version":"5.4.0-120-generic","architecture":"x64","version":"2.10.0","lang":"nodejs","lang_version":"16.13.0","env":"REMOTE_DEV","service":"speero-backend","agent_url":"http://127.0.0.1:8126/","debug":false,"sample_rate":1,"sampling_rules":[],"tags":{"service":"speero-backend","env":"REMOTE_DEV","version":"5.1.2","runtime-id":"8abdaf24-d606-4ca4-9581-8df502e5a45c"},"dd_version":"5.1.2","log_injection_enabled":true,"runtime_metrics_enabled":false,"profiling_enabled":false,"integrations_loaded":["fs","http2"],"appsec_enabled":false}

Steps to reproduce

tracer.init({
  logInjection: true,
  env: NODE_ENV,
  service: 'speero-backend'
});

tracer.use('express', {
  hooks: {
    request: (span, req: Request, res) => {
      span.setTag('http.route', req.route?.path || req.originalUrl);

      if (req.method === 'OPTIONS') {
        span.setTag('manual.drop', true);
      }
    }
  }
});

Environment

• Operation system: Linux 5.4.0-120-generic
• Node.js version: 16.13.0
• Tracer version: 2.10.0
• Agent version: 5.1.2
• Relevant library versions:

Is the above code the first thing happening in the entry point of the application? It looks like it could be a load order issue. There were never any guarantee for integrations to work when the tracer initialization is not the very first thing happening in the process, so sometimes it worked and sometimes it didn't. With the new plugin system, it's possible that something that used to work no longer works and vice versa if the tracer is initialized too late. I would start by making sure that the tracer initialization happens first as it's usually the cause of plugins not loading.

It's not the 1st thing that runs since we are using ESM I believe for it to be the entry point we have to use dd-trace node loader in CLI but unfortunately we are already using another loader so this is not possible at the moment. However it was working just fine using v2.6.0. If you could assist me as what change should I make without having to use dd-trace loader.

For ESM support to work properly, you'd need to use the loader. However, a loader is just a module that exports a few functions, so it should be straightforward to build your own loader that then calls both your existing loader and our loader one after the other and returns the result. I would recommend that approach since otherwise you might run into a lot of other issues when using ESM.

Problem is we're using our loader as a module alias resolver

// loader.js
import { readFile } from 'node:fs/promises';
const { paths } = JSON.parse(await readFile(new URL('./loader.paths.json', import.meta.url)));

export function resolve (specifier, context, defaultResolve) {
  const newSpecifier = getNewSpecifier(specifier);
  if (newSpecifier) {
    const { parentURL = null } = context;

    return {
      url: parentURL ?
        new URL(newSpecifier, parentURL).href :
        new URL(newSpecifier).href
    };
  }

  return defaultResolve(specifier, context, defaultResolve);
}

function getNewSpecifier (specifier) {
  const aliases = Object.keys(paths);

  for (const alias of aliases) {
    if (specifier.startsWith(alias)) {
      const directoryPath = new URL(paths[alias], import.meta.url).href;
      return specifier.replace(alias, directoryPath);
    }
  }
}

// loader.paths.json
{
  "paths": {
    "@config": "dist/config",
    "@helpers": "dist/helpers",
    "@modules": "dist/modules",
    "@test": "dist/test"
  }
}

Creating a new loader that calls your loader after ours wouldn't work because your loader would throw an error due to not being able to resolve the path and the only way for it to work is combining both loaders in one file by copy-pasting and modifying that file accordingly (correct me if I'm wrong).

This means I have to keep an eye on dd-trace loader each time I update the package and keep modifying the loader in case there was a change.

What changed from v2.6.0 to later versions that caused express integration not to load properly?

@ahmedelshenawy25 every new release they have breaks things and introduces new bugs;

I've been stuck on 2.2.0 because that is the only latest version that supports mongo properly

What changed from v2.6.0 to later versions that caused express integration not to load properly?

@ahmedelshenawy25 We've been moving everything to a new plugin system in the past few months, and there were also changes to how we hook into the module system of Node. If it was working before, then it might actually just be a load order issue, but with ESM in the mix I still wouldn't rule out the loader being needed. I remember seeing discussions about Node supporting multiple loaders, but I don't know if it ever resulted in any actual implementation.

Creating a new loader that calls your loader after ours wouldn't work

Could our loader be called first instead?

I've been stuck on 2.2.0 because that is the only latest version that supports mongo properly

@apank That could very well be a load order issue. Is the tracer initialized before any other module is imported? A good way to ensure this is to require it on the command line instead of in the process, for example with node -r dd-trace/init server.js, or if you need to programmatically configure the tracer then you would require your own initialization file instead with for example node -r ./datadog.js server.js. This can also be set with an environment variable if that's easier for your app with NODE_OPTIONS='-r dd-trace/init'.

If that doesn't work, we would need a reproduction snippet because I was never able to reproduce the issue with mongodb and our tests are all passing as well. I tried to break it on purpose and was still getting the spans.

Could our loader be called first instead?

@rochdev unfortunately it still won't be able to resolve our paths aliases

@ahmedelshenawy25 Can you provide an example of a case that doesn't work? It looks like Node supports multiple loaders since 18.6.0, so with an example of what doesn't work we should be able to hopefully fix the issue fairly easily.

@rochdev Sorry for the late reply. I didn't get the chance to try loader chaining till I upgrade to node 16.17.0.

So now I'm facing a new problem where node process is left hanging without starting the server. I tried to make a simplified example and surprisingly it worked. I'll try to debug the problem and provide you with an example if I could reproduce it. I'll close the issue for now.