Many spans created when .forEach is called on mongodb results

[millerick]

Describe the bug
We have one particular data retrieval that does the following operation on top of mongodb:

await this.buildQuery(ctx, opts, projection).forEach(doc => results.set(doc[key], doc));

The end results is many, many spans that are created. The first span that is created for this:

The last span that is created for this:

Since there is only one operation on the database, I would expect for only a single span to be created, despite the fact that each document in the result set is iterated over.

Environment

• Operation system: Ubuntu 16.04
• Node version: 12.14.1
• Tracer version: 0.15.4
• Agent version: 6 (I think?)

[rochdev]

This is because of the support for cursors, which may not really be useful. It should probably not be removed completely since that would be a breaking change, but there should definitely be an option to disable that if that's not relevant in some (most?) cases.

[millerick]

If that option were to exist, would that mean that all would be combined into one single span?

[rochdev]

If that option were to exist, would that mean that all would be combined into one single span?

Correct, you would have a single span for the entire duration of the query instead of one per individual cursor iteration.

[millerick]

Thank you, that would be much appreciated.

[millerick]

Any updates here, or guidance on roughly where in the library this change would need to be made? I'm happy to help with implementation.

[rochdev]

Any updates here

No update unfortunately.

guidance on roughly where in the library this change would need to be made?

The relevant code is here. In order to not have a breaking change, I think there should be an option to collapse cursor spans to a single span.

I'm happy to help with implementation.

We definitely welcome constributions! If you decide to do it and have any questions, please feel free to open an unfinished PR to ask for guidance :)

[rochdev]

@millerick It turns out it may not be possible to handle this in a generic way on the cursor. However, if you are never explicitly calling cursor.next(), then we could potentially instrument cursor.forEach explicitly and allow you to turn off individual next calls with a configuration option. Would that work for your use case?

[millerick]

@rochdev , that would work for our use case. We do not explicitly call cursor.next().

[rochdev]

@millerick After thinking about this more I think it actually makes more sense to do the opposite and instrument the actual underlying driver directly. This will provide more accurate results, which should also solve #719. The downside is that there would still be many spans for any collection method that uses cursors internally, but they would be labeled correctly with a query, multiple getMore and then a killCursors (when it applies).

Would that work for you as well? Merging everything into a single span while supporting all edge cases would require some pretty ugly hacks that would be nearly impossible to test and might reduce the accuracy of stats. Generally speaking, it also means hiding information since when using a cursor, there are in fact many calls made to the server to advance the cursor and consume documents, even if not apparent in the public interface.

[millerick]

@rochdev , yeah, that approach works as well. In saying that, I assume that there would be the appropriate number of getmores and not one span per document that is returned by the query.

[rochdev]

In saying that, I assume that there would be the appropriate number of getmores and not one span per document that is returned by the query.

It depends on the settings of the cursor. For example, if the batchSize is 1, then there would still be 1 span per document, but if the batch size is larger, then it would be reduced to the number of actual getMore commands. Basically, since we'd be patching the wire protocol part of the driver, every span means some communication was done with the server.

[millerick]

Yeah, which makes sense and is the valuable information.

[rochdev]

Fixed in #1159. Each span now correctly corresponds to an actual command sent to Mongo with more relevant metadata.