App Analytics doesn't seem to be working with Mongoose

[EricZaporzan]

Describe the bug

We added dd-trace to one of our projects and attempted to enable App Analytics on mongodb-core. Traces are captured and appear in Datadog, and analyzed spans for the top span are captured, but we don't seem to get analyzed spans from Mongo queries.

I believe this is a bug because:

1. we enabled analytics for other DBs in the same exact manner, and we do get analyzed spans for them (see config below).

2. traces for Mongo are captured and sent to Datadog as expected, so the tracer is surely being initialized before it's imported.

Environment

tracer.init({
  service: 'servicename',
  enabled: true,
  tags: {
    environment: 'test'
  },
  env: 'test',
  analytics: true
});

tracer.use('mongodb-core', { analytics: true });
tracer.use('elasticsearch', { analytics: true });
tracer.use('ioredis', { analytics: true });

• Operation system:

Linux on Docker

• Node version:

12.18.2

• Mongoose version

5.8.7

• Tracer version:

0.22.2

• Agent version:

latest

The library is working awesome overall, thanks for all the hard work you put into it! Let me know if I can provide any more info.

[rochdev]

I believe this is a bug

This is most certainly a bug as mongodb-core should be supported similar to other data stores. I'll have to look into it.

traces for Mongo are captured and sent to Datadog as expected, so the tracer is surely being initialized before it's imported

This is not necessarily the case. When the tracer is initialized after an instrumented module, it's possible the instrumentation will still work but with unexpected behavior. Can you share the top of your entry point, just to be sure the order is 100% correct?

[EricZaporzan]

@rochdev here it is:

process.env.NODE_ENV = process.env.NODE_ENV || 'development';

import config from 'config-dug'; // No mongoose/mongo dependency
import axios from 'axios'; // No mongoose/mongo dependency
import './lib/apm/analytics'; // This file contains the APM initialization code shown above

import createApp from './app' // This file contains the Mongoose initialization call

[rochdev]

Do you know if the underlying call is using cursors? It looks like cursors don't currently add the analytics tag, so that may be why it's not working. You would be able to know if it's a cursor by checking if the Mongo span contains a mongodb.cursor.index tag.

[EricZaporzan]

@rochdev I poked around and there seem to be those cursor tags on most or all of our MongoDB traces.

I think there's a plot twist though: I'm looking closer and I don't see a single update-style call in our MongoDB trace history (going back 15 days). We associate logs and traces, and on logs where an update happened, the trace just has a blank spot where the MongoDB update would have gone.

So maybe there's a couple of issues happening here?

[rochdev]

It's possible it's because of how we track cursors which might ignore the actual start/end of the operation. I'll have to look into it. Is this something you can reproduce minimally in a snippet? This would help me figure out the exact issue and set up a test case for it.

[EricZaporzan]

👍 I'll give it a shot when I have some time and get back to you

[EricZaporzan]

The below snippet replicates the first issue (cursored queries not showing up in app analytics) but not the second issue. I'll have to see if there's anything special about our configuration and come back later.

(async () => {

  const tracer = require('dd-trace');

  tracer.init({
    service: 'test-service',
    enabled: true,
    tags: {
      environment: 'test'
    },
    env: 'test',
    analytics: true
  });

  tracer.use('mongodb-core', { analytics: true });

  const mongoose = require('mongoose');

  const mongooseInstance = new mongoose.Mongoose();

  const db = await mongooseInstance.connect('mongodb://localhost:27017/testService?retryWrites=true');

  const schema = new mongoose.Schema({ foo: 'string' });
  const model = db.model('testcollection', schema);

  await tracer.trace('test-trace',  async () => {
    const testDocument = await model.create({
      foo: 'bar'
    });

    await model.findById(testDocument.id);

    console.log('done!');
  });
})();

edit: In fact, even if I put all the Mongo initialization stuff above the tracer initialization stuff, the update spans ship fine.

[rochdev]

Fixed in #1159