Using with express async-await controller creates unlinked spans

[nirsky]

Hey! First thing, thanks for taking the time and effort for creating this plugin.

I noticed using async-await on the query does not link the mongoose span with the express span unless the query is executed with exec().

Here are some example:

Using then() - Links correctly

app.get('/mongo-then', (_req, res) => {
  userCollection.findOne({}).then((u) => res.status(200).send(u));
});

Using async-await with exec - Links correctly

app.get('/mongo-exec', async (_req, res) => {
  const user = await userCollection.findOne({}).exec();
  res.status(200).send(user);
});

---

Using async-await - Created 2 separate spans

• 1 span called get /mongo-async-await.
• 1 span called mongoose.users.findOne.

app.get('/mongo-async-await', async (_req, res) => {
  const u = await userCollection.findOne({});
  res.status(200).send(u);
});

Zipkin Screenshot:

---

I'm using TypeScript, attaching my set up for reference:
Typescript version: 3.8.3
tsconfig:

{
    "compilerOptions": {
        "target": "ES2017",
        "lib": ["ES2019", "DOM"],
        "rootDir": "lib",
        "outDir": "dist",
        "module": "commonjs",
        "moduleResolution": "node",
        "strict": false,
        "declaration": true,
        "sourceMap": true,
        "inlineSources": true,
        "types": ["node"],
        "allowSyntheticDefaultImports": true,
        "esModuleInterop": true
    }
}

[wdalmut]

Hi @nirsky, I think that is related to #16 i found the same problem in other projects open-telemetry/opentelemetry-js#940 and a the base pr is this one: open-telemetry/opentelemetry-js#926

Other interesting issues: open-telemetry/opentelemetry-js#752

I keep digging in this and i will report on this and #16

[wdalmut]

I have added a test case to cover this issue in #30

[nirsky]

Thanks for your quick reply!
I also encountered similar issues with mongodb-plugin.
Over there it didn't even report on some cases.

Is #30 containing a fix or only tests? (I guess only tests so far by looking at the code).

[wdalmut]

sadly only test cases to cover your issue. i am following this PR open-telemetry/opentelemetry-js#926 that should resolve this issue. i suspect that every open telemetry implementation actually suffer this problem in JS... I have reported the same for mysql...

[vmarchaud]

Even if open-telemetry/opentelemetry-js#926 resolves some bugs, i'm pretty sure it will not fixes this one because mongoose returns a "thenables" which is isn't covered by async hooks due a bug in V8 (see nodejs/node#22360).
What you could do however is patches every mongoose op to use true promise instead of thenables but that's kinda hard due to how the chaining works in mongoose.

[wdalmut]

@vmarchaud oh thank you for your feedback i digging more in the mongoose method list and try to prepare a big patch...

[wdalmut]

yep, @vmarchaud is totally right the problem is strictly related to "thenables", in the test case:

Promise.all([
  User
   .find({id: "_test"})
   .skip(1)
  .limit(2)
  .sort({email: 'asc'}),
  User.countDocuments()
])

if i force a true promise with .exec() method

Promise.all([
  User
   .find({id: "_test"})
   .skip(1)
  .limit(2)
  .sort({email: 'asc'}).exec(),
  User.countDocuments().exec()
])

everything is correctly linked together. Same with your use case with .exec() and async...

This is not simple and i actually i don't understand how to change the mongoose flow in true promises and keeping the project workflow unchanged...

[wdalmut]

This should be fixed by #34