outgoing http.request instrumentation exacerbates node issue with ipv6 addresses

[trentm]

I have an express server with a 'GET /ping' endpoint running on localhost (port 3000) on macOS. When I run this (using node v16):

var http = require('http')
theUrl = 'http://[::1]:3000/ping'
http.get(theUrl, function (res) {
  console.log('res:', res.statusCode, res.headers)
  res.on('data', (chunk) => { console.log('data: %s', chunk) })
  res.on('end', () => { console.log('end') })
})

I get:

% node foo.js
res: 200 {
  'x-powered-by': 'Express',
  'content-type': 'text/html; charset=utf-8',
  'content-length': '4',
  etag: 'W/"4-DlFKBmK8tp3IY5U9HOJuPUDoGoc"',
  date: 'Wed, 20 Oct 2021 16:59:25 GMT',
  connection: 'close'
}
data: pong
end

All good. However, when I run this:

var http = require('http')
theUrl = {
  href: 'http://[::1]:3000/ping',
  pathname: '/ping',
  path: '/ping',
  protocol: 'http:',
  host: '[::1]:3000',
  port: '3000',
  hostname: '[::1]',
  hash: '',
  search: '',
  headers: {}
}
http.get(theUrl, function (res) {
  console.log('res:', res.statusCode, res.headers)
  res.on('data', (chunk) => { console.log('data: %s', chunk) })
  res.on('end', () => { console.log('end') })
})

I get this:

% node foo.js
node:events:368
      throw er; // Unhandled 'error' event
      ^

Error: getaddrinfo ENOTFOUND [::1]
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (node:dns:71:26)
Emitted 'error' event on ClientRequest instance at:
    at Socket.socketErrorListener (node:_http_client:447:9)
    at Socket.emit (node:events:390:28)
    at emitErrorNT (node:internal/streams/destroy:157:8)
    at emitErrorCloseNT (node:internal/streams/destroy:122:3)
    at processTicksAndRejections (node:internal/process/task_queues:83:21) {
  errno: -3008,
  code: 'ENOTFOUND',
  syscall: 'getaddrinfo',
  hostname: '[::1]'
}

That this behaviour differs in node strikes me as a bug, but I haven't looked into it yet.

the APM agent exacerbates this

Unfortunately, traceOutgoingRequest in the APM agent does exactly that transformation above. So when I add the agent to the first example:

require('.').start({ // elastic-apm-node
  serviceName: 'example-outgoing-http-ipv6-boom',
  cloudProvider: 'none',
  metricsInterval: '0s',
  centralConfig: false,
  captureExceptions: false,
  logUncaughtExceptions: true,
  disableSend: true
})

var http = require('http')
var theUrl = 'http://[::1]:3000/ping'
http.get(theUrl, function (res) {
  console.log('res:', res.statusCode, res.headers)
  res.on('data', (chunk) => { console.log('data: %s', chunk) })
  res.on('end', () => { console.log('end') })
})

I get this:

% node foo.js
node:events:368
      throw er; // Unhandled 'error' event
      ^

Error: getaddrinfo ENOTFOUND [::1]
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (node:dns:71:26)
    at GetAddrInfoReqWrap.callbackTrampoline (node:internal/async_hooks:130:17)
Emitted 'error' event on ClientRequest instance at:
    at Socket.socketErrorListener (node:_http_client:447:9)
    at Socket.emit (node:events:390:28)
    at emitErrorNT (node:internal/streams/destroy:157:8)
    at emitErrorCloseNT (node:internal/streams/destroy:122:3)
    at processTicksAndRejections (node:internal/process/task_queues:83:21) {
  errno: -3008,
  code: 'ENOTFOUND',
  syscall: 'getaddrinfo',
  hostname: '[::1]'
}

This came up now because with node v17.0.0 (released yesterday), we get the IPv6 [::1] for localhost back from more APIs. E.g. From mongodb's "start" event. From fastify.listen():

% node --unhandled-rejections=strict test/instrumentation/modules/fastify/async-await.test.js
TAP version 13
# transaction name
ok 1 null
node:events:368
      throw er; // Unhandled 'error' event
      ^

Error: getaddrinfo ENOTFOUND [::1]
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (node:dns:72:26)
    at GetAddrInfoReqWrap.callbackTrampoline (node:internal/async_hooks:130:17)
Emitted 'error' event on ClientRequest instance at:
    at Socket.socketErrorListener (node:_http_client:447:9)
    at Socket.emit (node:events:390:28)
    at emitErrorNT (node:internal/streams/destroy:164:8)
    at emitErrorCloseNT (node:internal/streams/destroy:129:3)
    at processTicksAndRejections (node:internal/process/task_queues:83:21) {
  errno: -3008,
  code: 'ENOTFOUND',
  syscall: 'getaddrinfo',
  hostname: '[::1]'
}

Node.js v17.0.0

TODO

• [ ] look into whether this really is a core node bug
• [ ] change our newArgs handling in traceOutgoingRequest to not replace a given URL string with an options object. I think that should be possible. I believe we are only adding headers and not munging the URL.