startSpan('A'); startSpan('B') in the same async op: B should be a child of A, but isn't

[trentm]

If you start a span (B) in the same async operation as a preceding span (A), the current agent (v3.8.0) will make A and B siblings. I think B should be a child span of A.

If you'd like to test your own expectations, here is a sort of survey: https://gist.github.com/trentm/63e5dbdeded8b568e782d1f24eab9536

Works as expected: each span in separate async ops

The common case (at least I assume) in node.js is that code significant enough to be a traced span are in separate async ops on the node.js event loop. E.g.:

app.get('/my-endpoint', (req, res) => {
  var A = apm.startSpan('this is span A')
  setTimeout(function () {
    var B = apm.startSpan('this is span B')
    setTimeout(function () {
      B.end()
      A.end()
    }, 10)
  }, 10)
})

For this case, the APM agent generates a trace like this (where indentation denotes a parent/child relationship):

- transaction: GET /my-endpoint
    - span: this is span A
        - span: this is span B

This works as I'd expect.

The contested case: multiple spans started in the same async op

app.get('/my-endpoint', (req, res) => {
  var A = apm.startSpan('this is span A')

  var B = apm.startSpan('this is span B')
  B.end()

  A.end()
})

For this code, the current APM agent generates a trace like this:

- transaction: GET /my-endpoint
    - span: this is span A
    - span: this is span B

I think this is a bug, or at least should be considered. My expectation for the above code is a trace like this:

- transaction: GET /my-endpoint
    - span: this is span A
        - span: this is span B

The patch

If you want to try it out, here is a patch to lib/instrumentation/index.js that changes to my expected behaviour: https://gist.github.com/trentm/63e5dbdeded8b568e782d1f24eab9536#file-the-diff
I'll start a draft PR in a little bit with that.

Proposal

• Get a feel for the test suite fall out.
• Discuss with others whether their expectations are the same (so far it is just @astorm and I).
• Try to come up with counter examples where the current behaviour is preferred.
• If considering changing this behaviour, do we consider it a breaking changing? I'm not aware of specific documentation on this scenario, but I haven't looked very hard. The patch does result in at least a few failing tests.

[trentm]

User evidence supporting this ticket:

Dario
I also don’t fully understand why sometimes there is a parent-child relationship between spans and sometimes there isn’t. it seems kind of random?

Dario
if I await Promise.resolve() after creating a span and calling client.search, a parent-child relationship is created between the span I created and the HTTP/ES spans.