[instrumentation-mongodb] test failing for [email protected]

[pichlermarc]

Description:
[email protected] released with a refactor that changed how the internal Connection.command() works, so no spans are generated and test fail.

In the instrumentation, we heavily rely on command, see

opentelemetry-js-contrib/plugins/node/opentelemetry-instrumentation-mongodb/src/instrumentation.ts

Lines 495 to 506 in 2e9fce4

	const currentSpan = trace.getSpan(context.active());
	const resultHandler = callback;
	const commandType = Object.keys(cmd)[0];
	if (
	typeof resultHandler !== 'function' ||
	typeof cmd !== 'object' ||
	cmd.ismaster ||
	cmd.hello
	) {
	return original.call(this, ns, cmd, options, callback);
	}

Since the signature changed we return original.call() instead of instrumenting. resultHandler is undefined and therefore not a function. also the other args have changed, see below. Right now I think this is not causing problems in end-user apps but if it is, we should temporarily disable [email protected] instrumentation until a fix is ready.

Resources:

• connection.ts at [email protected] - works
• connection.ts at [email protected] - fails

See failing test on main

• https://github.com/open-telemetry/opentelemetry-js-contrib/actions/runs/8093744773/job/22167022286
• I restarted the test for 18.18.2 on main after seeing failures in chore(deps): update deps matching "@opentelemetry/*" #1978

[pichlermarc]

cc @david-luna might be of interest for you as I seem to remember you working on this instrumentation before 🙂

[trentm]

Yah, I was poking David as well ;)
I took a look, and in v6.4.0 the signature of ConnectionPool.checkOut changed:

-  checkOut(callback: Callback<Connection>): void {
+  async checkOut(): Promise<Connection> {

This breaks this patch in instr-mongodb/src/instrumentation.ts

  // This patch will become unnecessary once
  // https://jira.mongodb.org/browse/NODE-5639 is done.
  private _getV4ConnectionPoolCheckOut() {
    return (original: V4ConnectionPool['checkOut']) => {
      return function patchedCheckout(this: unknown, callback: any) {
        const patchedCallback = context.bind(context.active(), callback);
        return original.call(this, patchedCallback);
      };
    };
  }

[david-luna]

Hi @trentm @pichlermarc

Thanks for the heads up :) I'm going to work on it today

[trentm]

Some issues here:

ConnectionPool.checkOut signature change

In mongodb/node-mongodb-native#3986 ConnectionPool.checkOut changed:

-  checkOut(callback: Callback<Connection>): void {
+  async checkOut(): Promise<Connection> {

which breaks our instrumentation:

  private _getV4ConnectionPoolCheckOut() {
    return (original: V4ConnectionPool['checkOut']) => {
      return function patchedCheckout(this: unknown, callback: any) {
        const patchedCallback = context.bind(context.active(), callback);
        return original.call(this, patchedCallback);
      };
    };
  }

My observation from this same issue with the Elastic Node.js APM agent is that
the async context loss for which this patch was added is no longer an issue.
So my guess is that we can just not do this patch for >=6.4.0 with something like:

--- a/plugins/node/opentelemetry-instrumentation-mongodb/src/instrumentation.ts
+++ b/plugins/node/opentelemetry-instrumentation-mongodb/src/instrumentation.ts
@@ -97,7 +97,7 @@ export class MongoDBInstrumentation extends InstrumentationBase {
       ),
       new InstrumentationNodeModuleDefinition<any>(
         'mongodb',
-        ['4.*', '5.*', '6.*'],
+        ['4.*', '5.*', '>=6.0.0 <6.4.0'],
         undefined,
         undefined,
         [

However, before that there is another breakage that results in spans not getting created.

Connection.command signature change

In mongodb/node-mongodb-native#3952 the Connection.prototype.command method in "src/cmap/connection.ts" was changed from:

  command(
    ns: MongoDBNamespace,
    command: Document,
    options: CommandOptions | undefined,
    callback: Callback
  ): void {

to:

  public async command(
    ns: MongoDBNamespace,
    command: Document,
    options: CommandOptions = {}
  ): Promise<Document> {

The current instrumentation patches that callback, which is now undefined. It will need to change to watch the returned Promise.

One thing I wasn't sure of is that the current instrumentation already has a guard to not startSpan if that callback is undefined, so I'm not sure what cases that is meant to handle.

I'm moving on for now. Happy if someone else wants to take this.