fix: context activation for HTTP instrumentation's outgoing requests

[seemk]

Which problem is this PR solving?

A while ago context activation was removed from outgoing HTTP requests due to wrong context being activated, here: #1546

However with net module instrumentation connect spans were attached to the parent span of the request, which is wrong. Besides the wrong context (parent) context was being activated in the response callbacks (data event) even if the response was not yet finished this made it impossible accessing the outgoing request span inside the response callbacks (e.g. when processing data chunks).

Short description of the changes

Before

context.with(parent, () => {
  http.get(url, response => {
    /* active context: parent */
    response.on('data', () => { /* active context: parent */ });
    response.on('end', () => { /* active context: parent */ });
});

After

context.with(parent, () => {
  http.get(url, response => {
    /* active context: outgoing request */
    response.on('data', () => { /* active context: outgoing request */ });
    response.on('end', () => { /* active context: parent */ });
});

Example: chaining outgoing requests for an incoming request

app.get('/foo', (req, res) => {
  /* active context: incoming request */
  https.get('https://www.google.com', (response) => {
    /* active context: outgoing request to www.google.com */
    response.on('chunk', () => { /* active context: outgoing request to www.google.com */ });
    response.on('end', () => {
      /* active context: incoming request */
      http.get('http://www.example.com', (response2) => {
         /* active context: outgoing request to www.example.com */
        response2.on('chunk', () => { /* active context: outgoing request to www.example.com */ });
        response2.on('end', () => {
          /* active context: incoming request */
          res.send("ok\n");
        });
      });
    });
  });
});

Which will produce a trace similar to this (net instrumentation is enabled here, thus the connect spans):

Remarks

• There's a custom event emitter binder pretty much the same as is in @opentelemetry/context-async-hooks, however I decided not to request a change to ContextManager interface of @opentelemetry/api to add a bind method which instead of taking in a context, takes in a function which returns a context and opted for some code duplication. This is useful for event emitters which might require different contexts being activated based on the events.

[codecov]

Codecov Report

Merging #2037 (c7bdf81) into main (b50f837) will increase coverage by 0.07%.
The diff coverage is 100.00%.

❗ Current head c7bdf81 differs from pull request most recent head b88ecac. Consider uploading reports for the commit b88ecac to get more accurate results

@@            Coverage Diff             @@
##             main    #2037      +/-   ##
==========================================
+ Coverage   92.98%   93.06%   +0.07%     
==========================================
  Files         152      153       +1     
  Lines        5934     5983      +49     
  Branches     1247     1257      +10     
==========================================
+ Hits         5518     5568      +50     
+ Misses        416      415       -1     

Impacted Files	Coverage Δ
...ges/opentelemetry-instrumentation-http/src/http.ts	95.65% <100.00%> (+0.14%)	⬆️
...es/opentelemetry-instrumentation-http/src/patch.ts	100.00% <100.00%> (ø)
...emetry-core/src/platform/node/RandomIdGenerator.ts	93.75% <0.00%> (+6.25%)	⬆️

[Flarna]

I don't think that response event should have the outgoing request span on active context.
If someone triggers a followup request (client HTTP, database,...) this would be child which is not intended (see #1479).

I think the span for the outgoing request should be set as active for the http.request() call only but the callbacks/events should be bound to the parent context.

This would fix the issue with net (and most likely also dns) instrumentation without changing the whole span tree.

[seemk]

I don't think that response event should have the outgoing request span on active context.
If someone triggers a followup request (client HTTP, database,...) this would be child which is not intended (see #1479).

I think the span for the outgoing request should be set as active for the http.request() call only but the callbacks/events should be bound to the parent context.

This would fix the issue with net (and most likely also dns) instrumentation without changing the whole span tree.

response is emitted once the response headers are received, the request is not yet finished, thus I think it is wrong to do any follow up requests after you have received the response headers and any such followups be done in the response.on('end', ...) event handler.

[Flarna]

What's wrong in issuing a followup operation already in response event if all the needed information is present?
What about other events like error, close?

[seemk]

What's wrong in issuing a followup operation already in response event if all the needed information is present?
What about other events like error, close?

Nothing wrong with that, it's a question of which context to activate in the response callback. The outgoing request context needs to be made available in at least one location. This is not related to net instrumentation, but an option to have access to the outgoing request's span inside the callbacks. data callback is not called for empty response bodies, thus my reasoning to activate the outgoing request context inside the response handler as well. The parent context will still be accessible on response end handler.

[dyladan]

I disagree that in your original example the current behavior is incorrect. If I make a request to http://example.com/api/tasks, wait for a response, and make a request to http://example.com/api/task/:id when I receive chunks of that response, the /api/task/:id calls are not children of the /api/tasks call but siblings.

[seemk]

I disagree that in your original example the current behavior is incorrect. If I make a request to http://example.com/api/tasks, wait for a response, and make a request to http://example.com/api/task/:id when I receive chunks of that response, the /api/task/:id calls are not children of the /api/tasks call but siblings.

Perhaps, but in a sense isn't the outgoing context lost forever then?

[Flarna]

It's at least serialized by api.propagation.inject and picked up on remote.

My expectation on the span tree are as follows. Assume an incoming http request which does two outgoing and remote process is also monitored:

IncomingHttpSpan
    ClientHttpSpan1
        NetConnectSpan1
            DnsLookupSpan1
        IncomingHttpSpan1 (remote process)
    ClientHttpSpan2
        NetConnectSpan2
            DnsLookupSpan2
        IncomingHttpSpan2 (remote process)

I'm not 100% sure if DnsLookup should be a child of NetConnect but I think it should.

[seemk]

It is picked up by inject indeed, but if I wanted to add attributes to the outgoing span?

[dyladan]

It is picked up by inject indeed, but if I wanted to add attributes to the outgoing span?

That sounds like a usecase for something like the applyCustomAttributesOnSpan config. Not supported by the net instrumentation module currently, but by the http instrumentation module and I believe the XHR/fetch modules as well.

[dyladan]

We talked about this at the SIG meeting today and the current behavior is the desired behavior. I am going to close this PR for now. If you disagree you can comment here and it could be reopened if there is reason to do so.

[seemk]

We talked about this at the SIG meeting today and the current behavior is the desired behavior. I am going to close this PR for now. If you disagree you can comment here and it could be reopened if there is reason to do so.

In any case I'll modify it so the connect spans are linked correctly (i.e. activating the request context when doing the call)

[weyert]

I am wondering if it would be useful to introduce applyCustomAttributesOnSpan to the net instrumentation?

[dyladan]

I am wondering if it would be useful to introduce applyCustomAttributesOnSpan to the net instrumentation?

It could be but this is a separate issue

[dyladan]

We talked about this at the SIG meeting today and the current behavior is the desired behavior. I am going to close this PR for now. If you disagree you can comment here and it could be reopened if there is reason to do so.

In any case I'll modify it so the connect spans are linked correctly (i.e. activating the request context when doing the call)

Are you going to modify this PR or open a new one for that?

[seemk]

We talked about this at the SIG meeting today and the current behavior is the desired behavior. I am going to close this PR for now. If you disagree you can comment here and it could be reopened if there is reason to do so.

In any case I'll modify it so the connect spans are linked correctly (i.e. activating the request context when doing the call)

Are you going to modify this PR or open a new one for that?

I'll open a new one