open-telemetry / opentelemetry-js

OpenTelemetry JavaScript Client
https://opentelemetry.io
Apache License 2.0
2.77k stars 810 forks source link

Instrumenting a Remix V2 application to have automatic incoming/outgoing tracing #4990

Open ademartini-czi opened 2 months ago

ademartini-czi commented 2 months ago

What happened?

Steps to Reproduce

Is it possible to automatically instrument HTTP incoming and outgoing spans when using Remix 2? I'm trying to do this with a regular auto-generated Remix 2 app (npx create-remix@latest). I'm running the latest (2.12.0) with both "@opentelemetry/instrumentation-http": "^0.53.0" and "opentelemetry-instrumentation-remix": "^0.7.1" and it doesn't seem to create any spans. It only works if I start manually making spans in my routes.

I know the remix instrumentation library isn't working because it keeps saying: RemixInstrumentation Module @remix-run/server-runtime has been loaded before RemixInstrumentation so it might not work, please initialize it before requiring @remix-run/server-runtime. And @opentelemetry/instrumentation-http doesn't seem to produce anything on its own either. Maybe Remix isn't using node HTTP?

Expected Result

It should be possible to automatically create trace spans for incoming/outgoing HTTP without pain using Remix V2.

Actual Result

No spans unless I manually create them.

Additional Details

OpenTelemetry Setup Code

This is what I'm doing at the start of my `entry.server.ts`:

diag.setLogger(new DiagConsoleLogger(), DiagLogLevel.WARN);

const resource = new Resource({
  [SemanticResourceAttributes.SERVICE_NAME]: "service1",
});
const provider = new NodeTracerProvider({
  resource,
  idGenerator: new AWSXRayIdGenerator(),
  sampler: new AlwaysOnSampler(),
});

provider.addSpanProcessor(
  new SimpleSpanProcessor(
    new OTLPTraceExporter({
      url: "http://localhost:4318/v1/traces",
    })
  )
);

provider.register({
  propagator: new AWSXRayPropagator(),
});

const httpConfig = {};

// eslint-disable-next-line @typescript-eslint/no-explicit-any
const instrumentations: InstrumentationBase<any>[] = [
  new HttpInstrumentation(httpConfig),
  new AwsInstrumentation(),
  new RemixInstrumentation(),
];

registerInstrumentations({
  instrumentations,
});

### package.json

```JSON
{
  "name": "tracing-test-1",
  "private": true,
  "sideEffects": false,
  "type": "module",
  "scripts": {
    "build": "remix vite:build",
    "dev": "remix vite:dev",
    "lint": "eslint --ignore-path .gitignore --cache --cache-location ./node_modules/.cache/eslint .",
    "start": "remix-serve ./build/server/index.js",
    "typecheck": "tsc"
  },
  "dependencies": {
    "@opentelemetry/api": "^1.9.0",
    "@opentelemetry/auto-instrumentations-node": "^0.50.0",
    "@opentelemetry/id-generator-aws-xray": "^1.2.2",
    "@opentelemetry/instrumentation-http": "^0.53.0",
    "@opentelemetry/propagator-aws-xray": "^1.26.0",
    "@opentelemetry/sdk-metrics": "^1.26.0",
    "@opentelemetry/sdk-node": "^0.53.0",
    "@opentelemetry/sdk-trace-node": "^1.26.0",
    "@remix-run/node": "^2.12.0",
    "@remix-run/react": "^2.12.0",
    "@remix-run/serve": "^2.12.0",
    "isbot": "^4.1.0",
    "opentelemetry-instrumentation-remix": "^0.7.1",
    "react": "^18.2.0",
    "react-dom": "^18.2.0"
  },
  "devDependencies": {
    "@remix-run/dev": "^2.12.0",
    "@types/react": "^18.2.20",
    "@types/react-dom": "^18.2.7",
    "@typescript-eslint/eslint-plugin": "^6.7.4",
    "@typescript-eslint/parser": "^6.7.4",
    "autoprefixer": "^10.4.19",
    "eslint": "^8.38.0",
    "eslint-import-resolver-typescript": "^3.6.1",
    "eslint-plugin-import": "^2.28.1",
    "eslint-plugin-jsx-a11y": "^6.7.1",
    "eslint-plugin-react": "^7.33.2",
    "eslint-plugin-react-hooks": "^4.6.0",
    "postcss": "^8.4.38",
    "tailwindcss": "^3.4.4",
    "typescript": "^5.1.6",
    "vite": "^5.1.0",
    "vite-tsconfig-paths": "^4.2.1"
  },
  "engines": {
    "node": ">=20.0.0"
  }
}

Relevant log output

No response

peterabbott commented 2 months ago

I am seeing this too. since 0.53 incoming/outgoing are not longer instrumented. The opt-opt/in properties appear to not change behaviour. Rolling back to 0.52.0 the span on incoming/outcoming requests work again

peterabbott commented 2 months ago

At a stab, something in this PR seems to have changed behaviour https://github.com/open-telemetry/opentelemetry-js/pull/4643

dyladan commented 2 months ago

RemixInstrumentation Module @remix-run/server-runtime has been loaded before RemixInstrumentation so it might not work, please initialize it before requiring @remix-run/server-runtime

This is most likely the problem. Because Remix is required before the instrumentation is initialized, it is already in the cache. We instrument by intercepting the require. If we can't do that, there is no way for us to instrument a module reliably.

And @opentelemetry/instrumentation-http doesn't seem to produce anything on its own either. Maybe Remix isn't using node HTTP?

I'm not sure, I don't know anything about Remix. If it used fetch or undici it would not use http. It seems somewhat likely this is the issue. There is an undici instrumentation that might fix that part.

trentm commented 2 months ago

An option might be to initialize OpenTelemetry in a separate file and then set NODE_OPTIONS="--require ./my-otel-setup-file.js".

trentm commented 2 months ago

And @opentelemetry/instrumentation-http doesn't seem to produce anything on its own either. Maybe Remix isn't using node HTTP?

I quickly played with a Remix app (via npx create-remix@latest).

npm run build
NODE_DEBUG=http npm start

curl -i http://localhost:3000   # to hit the Remix service

Using NODE_DEBUG=http, you can see that the http module is being used. Then I did:

npm install @opentelemetry/auto-instrumentations-node
NODE_OPTIONS=--require=@opentelemetry/auto-instrumentations-node/register OTEL_TRACES_EXPORTER=console OTEL_NODE_DISABLED_INSTRUMENTATIONS=fs OTEL_NODE_RESOURCE_DETECTORS=none npm start

curl -i http://localhost:3000   # to hit the Remix service

(The OTEL_NODE_DISABLED_INSTRUMENTATIONS=fs OTEL_NODE_RESOURCE_DETECTORS=none is to reduce some of the noise that isn't relevant here.)

The result is that you can see HTTP spans being created, so it is possible here.

pichlermarc commented 2 months ago

Ahh, I just saw this in the package.json you posted above:

  "type": "module",

When running it, do you add the ESM loader hook when calling the node executable? See this doc for details.

shmuli9 commented 1 month ago

Just to add a little context in case it was missed

Single fetch in remix (whicb will be the default in remix v3/react-router v7, and I’m guessing that’s what the author of this is setup with) you are most certainly using undici under the hood

@trentm I'm guessing the reason you see HTTP being used in your experiment is because you are running a vanilla remix setup and havn’t setup single fetch

Given this, I’m curious what it would actually take to correctly instrument a remix app using undici?

JamieDanielson commented 1 month ago

instrument a remix app using undici?

I think this one may be a separate question from the original post, but could be related. For undici there is a specific undici instrumentation that should be used, not just the http instrumentation.

The auto-instrumentations-node package can be used directly to include all packages (getNodeAutoInstrumentations()) instead of specifying individual instrumentations, which might help see what else gets picked up. Or add in new UndiciInstrumentation() to the list of instrumentations.

One thing to check is whether this single_fetch is enabled, which suggests that undici will be used.

trentm commented 1 month ago

@ademartini-czi Is this still an issue for you? If so, if you could provide enough code to fully reproduce what you are seeing, that would help us to identify what you are hitting.

dmvianna commented 1 month ago

I got Honeycomb working just by placing the telemetry code into app/entry.client.tsx. You should try there.