opentelemetry-js: `Can not execute the operation on ended Span` / `tls.connect .. You can only call end() on a span once.`

What happened?

Steps to Reproduce

Run a private repo using nodemon

Expected Result

<nothing>

Actual Result

logs

Additional Details

Seems related to:

OpenTelemetry Setup Code

/* eslint-disable no-console -- this file cannot use the proper logger
 */

import { createAzureSdkInstrumentation } from '@azure/opentelemetry-instrumentation-azure-sdk'
import { OTLPTraceExporter } from '@opentelemetry/exporter-trace-otlp-proto'
import { registerInstrumentations } from '@opentelemetry/instrumentation'
import { DnsInstrumentation } from '@opentelemetry/instrumentation-dns'
import { ExpressInstrumentation } from '@opentelemetry/instrumentation-express'
import { HttpInstrumentation } from '@opentelemetry/instrumentation-http'
import { NetInstrumentation } from '@opentelemetry/instrumentation-net'
import { WinstonInstrumentation } from '@opentelemetry/instrumentation-winston'
import { Resource } from '@opentelemetry/resources'
import {
  BatchSpanProcessor,
  NoopSpanProcessor,
} from '@opentelemetry/sdk-trace-base'
import { NodeTracerProvider } from '@opentelemetry/sdk-trace-node'
import { SemanticResourceAttributes } from '@opentelemetry/semantic-conventions'
import { getCurrentLoggerMetadata } from './common/logger-metadata-context'
import { getVersionString } from './common/version-string'
import type { SpanExporter, SpanProcessor } from '@opentelemetry/sdk-trace-base'

/*
 * This file is responsible for initializing OpenTelemetry. It is preloaded by
 * Node.js, so it can be used to initialize OpenTelemetry before any other code
 * is executed.
 *
 * It's important that this file does not import any other non-essential modules,
 * because those modules may be instrumented by OpenTelemetry and importing them
 * here would break the instrumentation.
 */

main()

function main() {
  const resource = createResource()

  const provider = new NodeTracerProvider({
    resource,
  })

  const exporter = createExporter()

  const spanProcessor = createSpanProcessor(exporter)

  provider.addSpanProcessor(spanProcessor)
  provider.register()

  registerInstrumentations({
    instrumentations: [
      new HttpInstrumentation({
        ignoreIncomingPaths: ['/health'],
      }),
      new WinstonInstrumentation({
        logHook: (_, record) => {
          const currentLoggerMetadata = getCurrentLoggerMetadata()
          if (currentLoggerMetadata !== undefined) {
            Object.assign(record, currentLoggerMetadata)
          }
        },
      }),
      new ExpressInstrumentation(),
      new DnsInstrumentation(),
      new NetInstrumentation(),
      createAzureSdkInstrumentation(),
    ],
    tracerProvider: provider,
  })

  const exitHandler = () => {
    console.log('Shutting down OpenTelemetry...')
    // Schedule the shutdown to happen after the current event loop iteration
    // completes. This is necessary because we want to give the exporter a
    // chance to send any remaining spans.
    provider
      .shutdown()
      .then(() => console.log('OpenTelemetry shutdown complete'))
      .catch((ex) => console.error('OpenTelemetry shutdown failed', ex))
  }

  process.on('SIGINT', exitHandler)
  process.on('SIGTERM', exitHandler)
}

function createResource(): Resource {
  const serviceName = process.env['NAME_SERVICE']
  const envName = process.env['ENVIRONMENT_NAME']

  return Resource.default().merge(
    new Resource({
      [SemanticResourceAttributes.SERVICE_NAME]: serviceName,
      service_name: serviceName,
      [SemanticResourceAttributes.SERVICE_NAMESPACE]: 'Namespace name',
      [SemanticResourceAttributes.SERVICE_VERSION]: getVersionString(),
      [SemanticResourceAttributes.DEPLOYMENT_ENVIRONMENT]: envName,
    }),
  )
}

function createExporter() {
  const exporterNameEnvVar = 'OTEL_TRACES_EXPORTER'
  const exporterName = process.env[exporterNameEnvVar]
  const isProduction = process.env['NODE_ENV'] === 'production'

  switch (exporterName) {
    case undefined:
    case '':
      if (isProduction) {
        console.error(
          'Opentelemetry span exporting has not been configured, and defaulted to off. This is probably a mistake in production.',
        )
      }
      return undefined
    case 'none':
      if (isProduction) {
        console.warn(
          'Opentelemetry span exporting has been explicitly disabled. This is probably a mistake in production.',
        )
      }
      return undefined
    case 'otlp':
      return new OTLPTraceExporter()
    default:
      throw new Error(
        `Unknown value received for the environment variable '${exporterNameEnvVar}'`,
      )
  }
}

function createSpanProcessor(
  exporter: SpanExporter | undefined,
): SpanProcessor {
  return exporter === undefined
    ? new NoopSpanProcessor()
    : new BatchSpanProcessor(exporter)
}

/* eslint-enable no-console */

package.json

"dependencies": {
    "@azure/opentelemetry-instrumentation-azure-sdk": "^1.0.0-beta.2",
    "@opentelemetry/api": "^1.3.0",
    "@opentelemetry/exporter-trace-otlp-proto": "^0.38.0",
    "@opentelemetry/instrumentation": "^0.38.0",
    "@opentelemetry/instrumentation-dns": "^0.31.0",
    "@opentelemetry/instrumentation-express": "^0.32.0",
    "@opentelemetry/instrumentation-http": "^0.41.0",
    "@opentelemetry/instrumentation-net": "^0.31.0",
    "@opentelemetry/instrumentation-winston": "^0.31.0",
    "@opentelemetry/resources": "^1.8.0",
    "@opentelemetry/sdk-trace-base": "^1.8.0",
    "@opentelemetry/sdk-trace-node": "^1.8.0",
    "@opentelemetry/semantic-conventions": "^1.8.0",
...
    "express": "^4.18.2",
    "express-basic-auth": "^1.2.1",
    "express-jwt": "^8.4.1",

Relevant log output

[WebServer] {
  "level": "warn",
  "message": "Can not execute the operation on ended Span {traceId: b77b886664c95c5e7e937f5a6200fcf0, spanId: 6a4d3ced1105c832}",
  "span_id": "78d5aca7fc8ac3c2",
  "timestamp": "2023-07-17T07:27:02.300Z",
  "trace_flags": "01",
  "trace_id": "b77b886664c95c5e7e937f5a6200fcf0"
}
{
  "level": "warn",
  "message": "Can not execute the operation on ended Span {traceId: b77b886664c95c5e7e937f5a6200fcf0, spanId: 6a4d3ced1105c832}",
  "span_id": "78d5aca7fc8ac3c2",
  "timestamp": "2023-07-17T07:27:02.301Z",
  "trace_flags": "01",
  "trace_id": "b77b886664c95c5e7e937f5a6200fcf0"
}
[WebServer] {
  "level": "error",
  "message": "tls.connect b77b886664c95c5e7e937f5a6200fcf0-6a4d3ced1105c832 - You can only call end() on a span once.",
  "span_id": "78d5aca7fc8ac3c2",
  "timestamp": "2023-07-17T07:27:02.301Z",
  "trace_flags": "01",
  "trace_id": "b77b886664c95c5e7e937f5a6200fcf0"
}

About this issue

  • Original URL
  • State: closed
  • Created a year ago
  • Reactions: 6
  • Comments: 17 (5 by maintainers)

Most upvoted comments

Hello everyone! Any progress? 🙃

Answering for my teammate @stdedos, we are seeing this on node 18