diff --git a/.changesets/warn-about-duplicate-opentelemetry-api-copies.md b/.changesets/warn-about-duplicate-opentelemetry-api-copies.md new file mode 100644 index 00000000..5f1e796f --- /dev/null +++ b/.changesets/warn-about-duplicate-opentelemetry-api-copies.md @@ -0,0 +1,9 @@ +--- +bump: patch +type: add +--- + +Warn when your application loads more than one version of +`@opentelemetry/api`, warning about potential data loss, as older versions +fail to send data through global values configured by newer versions. +The warning names the versions and where they were loaded from. diff --git a/src/__tests__/client.test.ts b/src/__tests__/client.test.ts index e277a6e2..d2081083 100644 --- a/src/__tests__/client.test.ts +++ b/src/__tests__/client.test.ts @@ -14,6 +14,7 @@ import { TraceFlags } from "@opentelemetry/api" import { BaseInternalLogger } from "../internal_logger" +import * as otelApiCopies from "../otel_api_copies" import { BaseLogger } from "../logger" describe("Client", () => { @@ -33,6 +34,44 @@ describe("Client", () => { await client.stop() }) + describe("duplicate @opentelemetry/api warning", () => { + beforeEach(() => { + otelApiCopies.resetDuplicateOpenTelemetryApiWarning() + }) + + it("says nothing when only one copy is loaded", () => { + jest + .spyOn(otelApiCopies, "duplicateOpenTelemetryApiWarningOnce") + .mockReturnValue(undefined) + const consoleWarn = jest.spyOn(console, "warn").mockImplementation() + const loggerWarn = jest + .spyOn(BaseInternalLogger.prototype, "warn") + .mockImplementation() + + client = new Client({ ...DEFAULT_OPTS, active: true }) + + expect(consoleWarn).not.toHaveBeenCalled() + expect(loggerWarn).not.toHaveBeenCalled() + }) + + it("warns to the console and the internal logger", () => { + jest + .spyOn(otelApiCopies, "duplicateOpenTelemetryApiWarningOnce") + .mockReturnValue("two copies of the API") + const consoleWarn = jest.spyOn(console, "warn").mockImplementation() + const loggerWarn = jest + .spyOn(BaseInternalLogger.prototype, "warn") + .mockImplementation() + + client = new Client({ ...DEFAULT_OPTS, active: true }) + + expect(consoleWarn).toHaveBeenCalledWith( + "appsignal WARNING: two copies of the API" + ) + expect(loggerWarn).toHaveBeenCalledWith("two copies of the API") + }) + }) + it("starts the extension when the client is active", () => { const startSpy = jest.spyOn(Extension.prototype, "start") client = new Client({ ...DEFAULT_OPTS, active: true }) diff --git a/src/__tests__/otel_api_copies.test.ts b/src/__tests__/otel_api_copies.test.ts new file mode 100644 index 00000000..479bca9e --- /dev/null +++ b/src/__tests__/otel_api_copies.test.ts @@ -0,0 +1,157 @@ +import fs from "fs" +import os from "os" +import path from "path" + +import { + duplicateOpenTelemetryApiWarning, + duplicateOpenTelemetryApiWarningOnce, + loadedOpenTelemetryApiCopies, + resetDuplicateOpenTelemetryApiWarning +} from "../otel_api_copies" + +describe("duplicateOpenTelemetryApiWarning", () => { + it("says nothing when only one copy is loaded", () => { + expect( + duplicateOpenTelemetryApiWarning([ + { version: "1.9.1", path: "/app/node_modules/@opentelemetry/api" } + ]) + ).toBeUndefined() + }) + + it("says nothing when no copy is loaded", () => { + expect(duplicateOpenTelemetryApiWarning([])).toBeUndefined() + }) + + it("says nothing when the copies differ only in their patch version", () => { + expect( + duplicateOpenTelemetryApiWarning([ + { version: "1.9.0", path: "/app/node_modules/@opentelemetry/api" }, + { + version: "1.9.1", + path: "/app/node_modules/other/node_modules/@opentelemetry/api" + } + ]) + ).toBeUndefined() + }) + + it("warns when the copies differ in their minor version", () => { + const warning = duplicateOpenTelemetryApiWarning([ + { version: "1.7.0", path: "/app/node_modules/@opentelemetry/api" }, + { + version: "1.9.1", + path: "/app/node_modules/other/node_modules/@opentelemetry/api" + } + ]) + + expect(warning).toContain("More than one version of @opentelemetry/api") + expect(warning).toContain("1.7.0 in /app/node_modules/@opentelemetry/api") + expect(warning).toContain( + "1.9.1 in /app/node_modules/other/node_modules/@opentelemetry/api" + ) + }) + + it("warns when the copies differ in their major version", () => { + expect( + duplicateOpenTelemetryApiWarning([ + { version: "1.9.1", path: "/app/node_modules/@opentelemetry/api" }, + { + version: "2.0.0", + path: "/app/node_modules/other/node_modules/@opentelemetry/api" + } + ]) + ).toContain("More than one version of @opentelemetry/api") + }) +}) + +describe("loadedOpenTelemetryApiCopies", () => { + let directory: string + let loaded: string[] + + beforeEach(() => { + directory = fs.mkdtempSync(path.join(os.tmpdir(), "otel-api-copies-")) + loaded = [] + }) + + afterEach(() => { + fs.rmSync(directory, { recursive: true, force: true }) + }) + + function fakeCopy(nestedIn: string | undefined, version: string) { + const root = path.join( + directory, + ...(nestedIn ? [nestedIn, "node_modules"] : []), + "@opentelemetry", + "api" + ) + + fs.mkdirSync(path.join(root, "build", "src"), { recursive: true }) + fs.writeFileSync( + path.join(root, "package.json"), + JSON.stringify({ name: "@opentelemetry/api", version }) + ) + + // The cache is keyed by the files a copy loaded, not by its directory, so + // the entry has to look like one of them. + const entry = path.join(root, "build", "src", "index.js") + fs.writeFileSync(entry, "") + loaded.push(entry) + + return root + } + + it("finds each loaded copy, with its version", () => { + const first = fakeCopy(undefined, "1.7.0") + const second = fakeCopy("some-library", "1.9.1") + + const found = loadedOpenTelemetryApiCopies(loaded) + + expect(found).toHaveLength(2) + expect(found).toContainEqual({ version: "1.7.0", path: first }) + expect(found).toContainEqual({ version: "1.9.1", path: second }) + }) + + it("reports one copy once, however many of its files are loaded", () => { + const root = fakeCopy(undefined, "1.9.1") + for (const name of ["trace.js", "context.js"]) { + const entry = path.join(root, "build", "src", name) + fs.writeFileSync(entry, "") + loaded.push(entry) + } + + const found = loadedOpenTelemetryApiCopies(loaded) + + expect(found).toEqual([{ version: "1.9.1", path: root }]) + }) +}) + +describe("duplicateOpenTelemetryApiWarningOnce", () => { + const incompatible = [ + { version: "1.7.0", path: "/app/node_modules/@opentelemetry/api" }, + { + version: "1.9.1", + path: "/app/node_modules/other/node_modules/@opentelemetry/api" + } + ] + + beforeEach(() => { + resetDuplicateOpenTelemetryApiWarning() + }) + + it("warns the first time and stays quiet after that", () => { + expect(duplicateOpenTelemetryApiWarningOnce(incompatible)).toContain( + "More than one version of @opentelemetry/api" + ) + expect(duplicateOpenTelemetryApiWarningOnce(incompatible)).toBeUndefined() + }) + + it("still warns later when the first look found nothing to say", () => { + const fine = [ + { version: "1.9.1", path: "/app/node_modules/@opentelemetry/api" } + ] + + expect(duplicateOpenTelemetryApiWarningOnce(fine)).toBeUndefined() + expect(duplicateOpenTelemetryApiWarningOnce(incompatible)).toContain( + "More than one version of @opentelemetry/api" + ) + }) +}) diff --git a/src/client.ts b/src/client.ts index c98bcaaf..b34481b2 100644 --- a/src/client.ts +++ b/src/client.ts @@ -9,6 +9,7 @@ import { demo } from "./demo" import { VERSION } from "./version" import { setParams, setSessionData } from "./helpers" import { BaseLogger, Logger, LoggerFormat, LoggerLevel } from "./logger" +import { duplicateOpenTelemetryApiWarningOnce } from "./otel_api_copies" import { diag, DiagConsoleLogger, DiagLogLevel } from "@opentelemetry/api" import { PeriodicExportingMetricReader, @@ -199,11 +200,29 @@ export class Client { if (this.config.data.initializeOpentelemetrySdk) { this.#sdk = this.initOpenTelemetry() this.setUpOpenTelemetryLogger() + this.warnAboutDuplicateOpenTelemetryApi() } this.initCoreProbes() } + /** + * Warns when the process has loaded more than one incompatible copy of + * `@opentelemetry/api`. + * + * Nothing else reports this. The copy that loses the version comparison is + * handed a tracer that drops every span, which looks the same as an + * application that produces no spans. It is said once per process, however + * many clients are built. + */ + private warnAboutDuplicateOpenTelemetryApi() { + const warning = duplicateOpenTelemetryApiWarningOnce() + if (!warning) return + + console.warn(`appsignal WARNING: ${warning}`) + Client.internalLogger.warn(warning) + } + public get isActive(): boolean { return this.#isActive } diff --git a/src/otel_api_copies.ts b/src/otel_api_copies.ts new file mode 100644 index 00000000..bbc8945b --- /dev/null +++ b/src/otel_api_copies.ts @@ -0,0 +1,111 @@ +import fs from "fs" +import path from "path" + +/** + * Finds the copies of `@opentelemetry/api` this process has loaded. + * + * Two copies in one project stop spans from being reported, and say nothing + * about it. The API keeps its tracer provider on a global keyed by major + * version, and a copy only reads that global when its own minor version is no + * higher than the minor version that wrote it. Whichever copy loses that + * comparison is handed a tracer that discards every span it is given. + * + * The loaded copies are what matters, rather than the copies on disk. A second + * copy that nothing requires does no harm, and walking `node_modules` to find + * it would cost more than reading a cache that is already in memory. + */ +export type OpenTelemetryApiCopy = { version: string; path: string } + +export function loadedOpenTelemetryApiCopies( + loadedFiles = Object.keys(require.cache) +): OpenTelemetryApiCopy[] { + const marker = path.join("@opentelemetry", "api") + path.sep + const roots = new Set() + + for (const filename of loadedFiles) { + const at = filename.lastIndexOf(marker) + if (at === -1) continue + + roots.add(filename.slice(0, at + marker.length - 1)) + } + + const copies: OpenTelemetryApiCopy[] = [] + + for (const root of roots) { + try { + const manifest = JSON.parse( + fs.readFileSync(path.join(root, "package.json"), "utf8") + ) + + if (manifest.name === "@opentelemetry/api" && manifest.version) { + copies.push({ version: manifest.version, path: root }) + } + } catch { + // A directory that looks like the package but has no readable manifest + // tells us nothing, so there is nothing to report about it. + } + } + + return copies +} + +/** + * Describes the problem when more than one incompatible copy of + * `@opentelemetry/api` is loaded, or returns `undefined` when the copies can + * all talk to each other. + * + * Copies differing only in their patch version are left alone. The API compares + * major and minor versions when it decides whether one copy may read another's + * global, so those copies are interchangeable, and `npm link` produces them + * routinely. + */ +export function duplicateOpenTelemetryApiWarning( + copies: OpenTelemetryApiCopy[] = loadedOpenTelemetryApiCopies() +): string | undefined { + const seen = new Set( + copies.map(copy => copy.version.split(".").slice(0, 2).join(".")) + ) + + if (seen.size < 2) return undefined + + const listed = copies + .map(copy => ` ${copy.version} in ${copy.path}`) + .sort() + .join("\n") + + return ( + "More than one version of @opentelemetry/api is loaded, so some spans " + + "will not be reported and nothing else will say so:\n" + + `${listed}\n` + + "Make your application and its dependencies agree on one version of " + + "@opentelemetry/api. If a dependency asks for a version that cannot be " + + "shared, updating it may be enough, and your package manager can force a " + + "single version if it is not." + ) +} + +let hasWarned = false + +/** + * The same as `duplicateOpenTelemetryApiWarning`, but only the first time it + * has something to say. + * + * A second `Client` would otherwise repeat a warning about the same tree. The + * module cache can still gain a copy later, so this stays quiet only once it + * has something to say: a first look that found nothing does not silence it. + */ +export function duplicateOpenTelemetryApiWarningOnce( + copies?: OpenTelemetryApiCopy[] +): string | undefined { + if (hasWarned) return undefined + + const warning = duplicateOpenTelemetryApiWarning(copies) + if (warning) hasWarned = true + + return warning +} + +/** @internal */ +export function resetDuplicateOpenTelemetryApiWarning() { + hasWarned = false +}