http plugin mark all http.request spans as error

[Grmiade]

Describe the bug
When our service receives an http response with a 200 status code. The span is marked as an error.
We have this issue since we upgraded to the 2.4.1 version, for all services and each http.request spans.

Environment

• Node version: 17.8.0
• Tracer version: 2.4.1

[jakst]

We're also seeing this from the v2.4.1 upgrade (we came from v2.2.0)

[rochdev]

We did made a few changes to the http integration in that version, but I can't find anything obvious that would cause this and was unable to reproduce this locally. Can you share a reproduction snippet?

[iainmcgin]

We (Gusto) were just impacted by this too - upgrading from 2.4.0 to 2.4.1 in our graphql gateway service resulted in all outgoing POST requests being marked as errors. After rolling back to 2.4.0, the errors subsided. GET requests were unaffected.

[rochdev]

@iainmcgin Just tried with a POST request and still not getting the error flag set to 1. Are you using a specific client or http directly? Can you share how it's used?

[iainmcgin]

Our graphql gateway is built using apollo-server, and the requests occur within the context of a RemoteGraphQLDataSource. I don't think we've customized the fetcher, and it looks like the default implementation uses make-fetch-happen, and from our lock file, looks like v8.0.14. I hope that helps!

[Grmiade]

@rochdev It seems the problem comes from the instrumentation.
asyncEndClientCh.publish is executed multiple times (response + close)
The close event is always called during a successful request. So this line will be executed since no third parameter is provided here. What do you think?

See https://nodejs.org/api/http.html#:~:text=In%20a%20successful,%27close%27

In a successful request, the following events will be emitted in the following order:

• 'socket'
• 'response'
  • 'data' any number of times, on the res object ('data' will not be emitted at all if the response body is empty, for instance, in most redirects)
  • 'end' on the res object
• 'close'

[Grmiade]

Moreover are you sure of this?

const finished = false
const finish = (finished, req, res) => {
  if (!finished) {
    finished = true // <|=====
    asyncEndClientCh.publish({ req, res })
  }
}

It seems you are reassigning the finished argument of the finish function and not the finished variable defined above.

[mb21]

We also have this after upgrading from 2.2.0 to 2.4.1 and we're using node-fetch 2.6.7 on node.js 16.13.

[rochdev]

@Grmiade That's definitely it. I'll figure out a test and release a fix as soon as possible.

[bcomnes]

Seeing this still, but only for HEAD requests in spans. They do not contain errors, but DD-trace is treating them as errors.

Rolling back to 2.4.0, this issue appears to gone, though HEAD request spans just totally disappear from spans... which I guess would hide the issue.

EDIT: opened an issue #2089

[tommoor]

I'm still seeing this problem with the latest version 3.9.3 – is it possible something regressed here? 🤔