Child traces not associated with correct parent

[bryanlarsen]

I added a 5 second delay to the server1 example in jaeger-node, and then did a few simultaneous requests. All child spans showed up as children of the first request, no child spans were associated with the subsequent requests.

[hekike]

@bryanlarsen do you have an idea why? I mean did you collect more information about this issue in the meantime?

[bryanlarsen]

No, I just dismissed opentracing-auto as broken by design.

The problem is trivial to reproduce with simultaneous requests to your example.

It'd require some pretty cool magic for the mongo wrapper to know which http request triggered the mongo call if there is more than one http request outstanding. I'd love to get some of that magic if there is some, but it looks like your code is fairly straightforward, not magical.

[hekike]

The "magic" is called continuation-local-storage and maybe there is a bug in this library but it is possible.

[bryanlarsen]

That is pretty magical! Thanks for the pointer.

A quick googling indicates that this isn't an uncommon occurrence, a good explanation is in the bottom section of https://datahero.com/blog/2014/05/22/node-js-preserving-data-across-async-callbacks/

The first thing I would suspect would be the mongodb connection pool -- the mongodb connection would have been created on the first request and reused for the second request, so it uses the local storage of the first request. Just a guess, though, could be something else. Something like https://github.com/tylerchr/cls-porqpine is probably needed in the example code.

I'll try and setup my test environment and try and get you either a PR or a better request. Won't be able to get to it today, though.

[hekike]

You are right, we cannot track absolutely everything.
RIght now the express / restify request handlers are the entry points (root span).

In the meantime, I replaced the asynctx library to the widely adopted cls-hooked, could you re-evaluate opentracing-auto?

Relased to npm as v1.5.2

[Puneeth-n]

@bryanlarsen any updates on #9 (comment)?

[leopoldodonnell]

Looks like cls-hooked doesn't really improve things. I experimented by augmenting with async-local-storage to squirrel away the root context (if one existed). I could also just verify there isn't a root-context in the stack, but that could give me the wrong root context on a busy server.

The challenge is to connect a pooled connection created with an earlier context to the present one.