Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Instrumentation not working #2390

Open
rubencosta13 opened this issue Aug 19, 2024 · 5 comments
Open

Instrumentation not working #2390

rubencosta13 opened this issue Aug 19, 2024 · 5 comments
Assignees

Comments

@rubencosta13
Copy link

What version of OpenTelemetry are you using?

"@opentelemetry/api": "^1.9.0",
"@opentelemetry/auto-instrumentations-node": "^0.49.1",
"@opentelemetry/exporter-logs-otlp-proto": "^0.52.1",
"@opentelemetry/exporter-metrics-otlp-proto": "^0.52.1",
"@opentelemetry/host-metrics": "^0.35.3",
"@opentelemetry/instrumentation-express": "^0.41.1",
"@opentelemetry/instrumentation-http": "^0.52.1",
"@opentelemetry/node": "^0.24.0",
"@opentelemetry/sdk-trace-node": "^1.25.1",

What version of Node are you using?

 node -v          
v20.16.0

What did you do?

I've put together a simple implementation of a class to consume opentelemetry with some custom stuff:

import { OTLPTraceExporter } from '@opentelemetry/exporter-trace-otlp-proto';
import { OTLPMetricExporter } from '@opentelemetry/exporter-metrics-otlp-proto';
import { Tracer, Meter } from '@opentelemetry/api';
import {
  NodeTracerProvider, ParentBasedSampler, SimpleSpanProcessor,
  TraceIdRatioBasedSampler
} from '@opentelemetry/sdk-trace-node';
import { Resource } from '@opentelemetry/resources';
import {
  MeterProvider, PeriodicExportingMetricReader
} from '@opentelemetry/sdk-metrics';
import {
  SemanticResourceAttributes
} from '@opentelemetry/semantic-conventions';
import * as opentelemetry from '@opentelemetry/api';
import { registerInstrumentations } from '@opentelemetry/instrumentation';
import {
  MongooseInstrumentation
} from '@opentelemetry/instrumentation-mongoose';
import { HostMetrics } from '@opentelemetry/host-metrics';
import { ExpressInstrumentation } from '@opentelemetry/instrumentation-express';
import { MongoDBInstrumentation } from '@opentelemetry/instrumentation-mongodb';
import { RedisInstrumentation } from '@opentelemetry/instrumentation-redis-4';
import { HttpInstrumentation } from '@opentelemetry/instrumentation-http';
import { logger } from '../utils/logger';

interface ISetupAnalytics {
  url: string;
  serviceName: string;
  metricsUrl: string;
}

class Analytics {
  private _tracer?: Tracer;
  private _meter?: Meter;
  private _meterProvider?: MeterProvider;
  private _provider?: NodeTracerProvider;

  get tracer() {
    if (!this._tracer && process.env.NODE_ENV !== 'test') {
      throw new Error('Cannot access tracer before initialization');
    }
    return this._tracer!;
  }

  get meter() {
    if (!this._meter && process.env.NODE_ENV !== 'test') {
      throw new Error('Cannot access meter before initialization');
    }
    return this._meter!;
  }

  get spanId() {
    return opentelemetry.trace.getActiveSpan();
  }

  private setupTraceExporter(url: string) {
    return new OTLPTraceExporter({ url });
  }

  private setupMetricExporter(url: string) {
    return new OTLPMetricExporter({ url });
  }

  private setupInstrumentation() {
    registerInstrumentations({
      instrumentations: [
        new MongooseInstrumentation({
          suppressInternalInstrumentation: true,
        }),
        new HttpInstrumentation(),
        new ExpressInstrumentation(),
        new MongoDBInstrumentation(),
        new RedisInstrumentation(),
      ],
      meterProvider: this._meterProvider,
      tracerProvider: this._provider
    });
  }

  private setupMetrics(serviceName: string) {
    new HostMetrics({
      meterProvider: this._meterProvider,
      name: serviceName,
    }).start();
  }

  async setup({ url, serviceName, metricsUrl }: ISetupAnalytics): Promise<void> {
    try {
      if (process.env.NODE_ENV === 'test') {
        return;
      }

      const traceExporter = this.setupTraceExporter(`${url}/v1/traces`);
      const metricExporter = this.setupMetricExporter(`${url}/metrics`);

      this._provider = new NodeTracerProvider({
        resource: new Resource({
          [SemanticResourceAttributes.SERVICE_NAME]: serviceName,
          [SemanticResourceAttributes.SERVICE_VERSION]: '0.1.0',
        }),
        sampler: new ParentBasedSampler({
          root: new TraceIdRatioBasedSampler(1.0),
        }),
      });

      this._meterProvider = new MeterProvider({
        readers: [
          new PeriodicExportingMetricReader({
            exporter: metricExporter,
            exportTimeoutMillis: 60000,
          }),
        ],
        resource: new Resource({
          [SemanticResourceAttributes.SERVICE_NAME]: serviceName,
        }),
      });

      this.setupMetrics(serviceName);
      this._provider.addSpanProcessor(new SimpleSpanProcessor(traceExporter));
      this.setupInstrumentation();

      this._provider.register();
      this._tracer = opentelemetry.trace.getTracer(`TRACER_${serviceName}`);
      this._meter = this._meterProvider.getMeter(`METER_${serviceName}`);

      logger.info('Telemetry Collection started');
    } catch (err) {
      logger.error('Error initializing OpenTelemetry', err);
      throw err;
    }
  }

  async shutdown() {
    if (this._provider) {
      await this._provider.shutdown();
      logger.info('Telemetry shutdown completed');
    }
  }
}

const analytics = new Analytics();
export { analytics, Analytics, opentelemetry };

However no matter what I try, autoinstrumentations are never working...

What did you expect to see?

Would love to see and test auto instrumentations

What did you see instead?

No instrumentation, only spans on jagger (see below)

Additional context

here is my collector:

receivers:
  otlp:
    protocols:
      grpc:
        endpoint: 0.0.0.0:4317
      http:
        endpoint: 0.0.0.0:4318

exporters:
  jaeger:
    endpoint: jaeger:14250
    tls:
      insecure: true

  prometheus:
    endpoint: 0.0.0.0:8888

processors:
  batch:

extensions:
  health_check:

service:
  extensions: [health_check]
  pipelines:
    traces:
      receivers: [otlp]
      processors: [batch]
      exporters: [jaeger]
    metrics:
      receivers: [otlp]
      processors: [batch]
      exporters: [prometheus]

Thank you in advance!

@rubencosta13 rubencosta13 added the bug Something isn't working label Aug 19, 2024
@trentm
Copy link
Contributor

trentm commented Aug 19, 2024

@rubencosta13 Can you please show a (possibly small) script that is using that setup TypeScript file above and how you are calling it? Also, ideally, if you could show the compiled JavaScript resulting from this TypeScript. Showing the small repro and the compiled JavaScript can help to clarify some things that can cause surprises with instrumentation:

  • order of imports and setup
  • whether CommonJS or ESM JavaScript is being used

@rubencosta13
Copy link
Author

Here is the compiled version (from TS to JS) using tsc:
This project is using ESM

"use strict";
var __createBinding = (this && this.__createBinding) || (Object.create ? (function(o, m, k, k2) {
    if (k2 === undefined) k2 = k;
    var desc = Object.getOwnPropertyDescriptor(m, k);
    if (!desc || ("get" in desc ? !m.__esModule : desc.writable || desc.configurable)) {
      desc = { enumerable: true, get: function() { return m[k]; } };
    }
    Object.defineProperty(o, k2, desc);
}) : (function(o, m, k, k2) {
    if (k2 === undefined) k2 = k;
    o[k2] = m[k];
}));
var __setModuleDefault = (this && this.__setModuleDefault) || (Object.create ? (function(o, v) {
    Object.defineProperty(o, "default", { enumerable: true, value: v });
}) : function(o, v) {
    o["default"] = v;
});
var __importStar = (this && this.__importStar) || function (mod) {
    if (mod && mod.__esModule) return mod;
    var result = {};
    if (mod != null) for (var k in mod) if (k !== "default" && Object.prototype.hasOwnProperty.call(mod, k)) __createBinding(result, mod, k);
    __setModuleDefault(result, mod);
    return result;
};
Object.defineProperty(exports, "__esModule", { value: true });
exports.opentelemetry = exports.Analytics = exports.analytics = void 0;
const exporter_trace_otlp_proto_1 = require("@opentelemetry/exporter-trace-otlp-proto");
const exporter_metrics_otlp_proto_1 = require("@opentelemetry/exporter-metrics-otlp-proto");
const sdk_trace_node_1 = require("@opentelemetry/sdk-trace-node");
const resources_1 = require("@opentelemetry/resources");
const sdk_metrics_1 = require("@opentelemetry/sdk-metrics");
const semantic_conventions_1 = require("@opentelemetry/semantic-conventions");
const opentelemetry = __importStar(require("@opentelemetry/api"));
exports.opentelemetry = opentelemetry;
const instrumentation_1 = require("@opentelemetry/instrumentation");
const instrumentation_mongoose_1 = require("@opentelemetry/instrumentation-mongoose");
const host_metrics_1 = require("@opentelemetry/host-metrics");
const instrumentation_express_1 = require("@opentelemetry/instrumentation-express");
const instrumentation_mongodb_1 = require("@opentelemetry/instrumentation-mongodb");
const instrumentation_redis_4_1 = require("@opentelemetry/instrumentation-redis-4");
const instrumentation_http_1 = require("@opentelemetry/instrumentation-http");
const logger_1 = require("../utils/logger");
class Analytics {
    _tracer;
    _meter;
    _meterProvider;
    _provider;
    get tracer() {
        if (!this._tracer && process.env.NODE_ENV !== 'test') {
            throw new Error('Cannot access tracer before initialization');
        }
        return this._tracer;
    }
    get meter() {
        if (!this._meter && process.env.NODE_ENV !== 'test') {
            throw new Error('Cannot access meter before initialization');
        }
        return this._meter;
    }
    get spanId() {
        return opentelemetry.trace.getActiveSpan();
    }
    setupTraceExporter(url) {
        return new exporter_trace_otlp_proto_1.OTLPTraceExporter({ url });
    }
    setupMetricExporter(url) {
        return new exporter_metrics_otlp_proto_1.OTLPMetricExporter({ url });
    }
    setupInstrumentation() {
        (0, instrumentation_1.registerInstrumentations)({
            instrumentations: [
                new instrumentation_mongoose_1.MongooseInstrumentation({
                    suppressInternalInstrumentation: true,
                }),
                new instrumentation_http_1.HttpInstrumentation(),
                new instrumentation_express_1.ExpressInstrumentation(),
                new instrumentation_mongodb_1.MongoDBInstrumentation(),
                new instrumentation_redis_4_1.RedisInstrumentation(),
            ],
            meterProvider: this._meterProvider,
            tracerProvider: this._provider
        });
    }
    setupMetrics(serviceName) {
        new host_metrics_1.HostMetrics({
            meterProvider: this._meterProvider,
            name: serviceName,
        }).start();
    }
    async setup({ url, serviceName, metricsUrl }) {
        try {
            if (process.env.NODE_ENV === 'test') {
                return;
            }
            const traceExporter = this.setupTraceExporter(`${url}/v1/traces`);
            const metricExporter = this.setupMetricExporter(`${url}/metrics`);
            this._provider = new sdk_trace_node_1.NodeTracerProvider({
                resource: new resources_1.Resource({
                    [semantic_conventions_1.SemanticResourceAttributes.SERVICE_NAME]: serviceName,
                    [semantic_conventions_1.SemanticResourceAttributes.SERVICE_VERSION]: '0.1.0',
                }),
                sampler: new sdk_trace_node_1.ParentBasedSampler({
                    root: new sdk_trace_node_1.TraceIdRatioBasedSampler(1.0),
                }),
            });
            this._meterProvider = new sdk_metrics_1.MeterProvider({
                readers: [
                    new sdk_metrics_1.PeriodicExportingMetricReader({
                        exporter: metricExporter,
                        exportTimeoutMillis: 60000,
                    }),
                ],
                resource: new resources_1.Resource({
                    [semantic_conventions_1.SemanticResourceAttributes.SERVICE_NAME]: serviceName,
                }),
            });
            this.setupMetrics(serviceName);
            this._provider.addSpanProcessor(new sdk_trace_node_1.SimpleSpanProcessor(traceExporter));
            this.setupInstrumentation();
            this._provider.register();
            this._tracer = opentelemetry.trace.getTracer(`TRACER_${serviceName}`);
            this._meter = this._meterProvider.getMeter(`METER_${serviceName}`);
            logger_1.logger.info('Telemetry Collection started');
        }
        catch (err) {
            logger_1.logger.error('Error initializing OpenTelemetry', err);
            throw err;
        }
    }
    async shutdown() {
        if (this._provider) {
            await this._provider.shutdown();
            logger_1.logger.info('Telemetry shutdown completed');
        }
    }
}
exports.Analytics = Analytics;
const analytics = new Analytics();
exports.analytics = analytics;

As for how I import it and setup:
Let me know if this is enough...

import { analytics } from './analytics/analytics';
import mongoose from 'mongoose';
import { httpServer } from './app';

const setupAnalytics = async () => {
    await analytics.setup({
    url: process.env.TELEMETRY_URL,
    serviceName: process.env.OTEL_SERVICE_NAME,
    metricsUrl: process.env.METRICS_URL
  });
}

const startFunction = () => {
   await setupAnalytics();
   await mongoose.connect(SOME_URL);
   httpServer.listen(3000);
}

startFunction();

I always make sure that analytics is the first thing to be imported, and call setup the very first thing

Thank you for your help!

@trentm
Copy link
Contributor

trentm commented Aug 20, 2024

@rubencosta13 My guess at the issue you are hitting is that your setupAnalytics() work (the code path that creates the Instrumentation class instances and calls registerInstrumentations) is too late. It is happening after the modules that you want instrumented have been imported. For example, the load of the 'mongoose' package happens before setupAnalytics runs.

The way OTel JS instruments packages (in most cases) is to setup a hook into Node.js's require and import mechanisms. Then when the package is loaded (by require(...) or from ... import '...', the OTel instrumentation tweaks the loaded package before the application code gets access to it.

If the application loads the package before those hooks are setup, then it is possible that the instrumentation hook never runs... or that it runs later, but too late because the application already had access to the uninstrumented package exports. I say "possible", because sometimes one can get "lucky" and instrumentation works even if the order is wrong.

To be sure, you want to setup OTel in a way that ensures its setup is complete before the application code runs. The recommended way (at least the way I recommend) is to (a) put your OTel setup code in a separate file (e.g. called "instrumentation.js" or "telemetry.js" -- or using ".ts" works if you are running via ts-node or compiling it) and then (b) call that setup file via one of Node.js's "preload" mechanisms: --require or --import. E.g.:

node --require ./telemetry.js my-app.js

or this is supported in more recent versions of Node.js:

node --import ./telemetry.js my-app.js

There are some possibly subtle differences between --require and --import that hopefully you don't need to worry about now.

Alternatively, you can put the OTel setup code at the top of your main file. However, you need to make sure it all sets up before any of your application code even does its imports. With TypeScript compilation and/or other transpilers there can be surprises that re-order imports to the top of a file.

surprises / subtleties

I mentioned CommonJS vs ESM above. The compiled .js code you posted is using require(...), so that is CommonJS code. That should mean you are fine using the node --require ./telemetry.js my-app.js above. If you are running ESM code (code using import ...) directly from Node.js, then the OpenTelemetry JS support for hooking and instrumenting with ESM is experimental and in flux of late.

Separately, it doesn't sound like you are using a bundler. If you do use a bundler, then there are more surprises there.

@trentm trentm self-assigned this Aug 21, 2024
@dyladan
Copy link
Member

dyladan commented Aug 28, 2024

@trentm can you please apply a priority label to this issue so it doesn't show up in the triage filter? If this isn't a bug you can remove the bug label

@trentm trentm removed the bug Something isn't working label Sep 4, 2024
@pichlermarc
Copy link
Member

@rubencosta13 were you able to try @trentm's recommendation? 🙂

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants