http/outgoing.test.js test failures with latest node v20 and v19.9.0 #3261

trentm · 2023-04-10T22:49:32Z

An example "Edge" run that fails: https://github.com/elastic/apm-agent-nodejs/actions/runs/4661845813/jobs/8251575055

Passes with v20.0.0-nightly202211186f9175deaa.
Fails with v20.0.0-nightly20230409c311dc43cd.
These aren't the boundary versions yet. Need to do a binary search.

Repro example:

NVM_NODEJS_ORG_MIRROR=https://nodejs.org/download/nightly nvm install v20.0.0-nightly202304102d1934aa96
node test/instrumentation/modules/http/outgoing.test.js

Full run example:

% NVM_NODEJS_ORG_MIRROR=https://nodejs.org/download/nightly nvm install v20
Downloading and installing node v20.0.0-nightly202304102d1934aa96...
Downloading https://nodejs.org/download/nightly/v20.0.0-nightly202304102d1934aa96/node-v20.0.0-nightly202304102d1934aa96-darwin-x64.tar.xz...
##################################################################################################################################################### 100.0%
Computing checksum with sha256sum
Checksums matched!
Now using node v20.0.0-nightly202304102d1934aa96 (npm v9.6.4)

% node test/instrumentation/modules/http/outgoing.test.js
TAP version 13
# http.request(options)
ok 1 should have traceparent header
ok 2 should have elastic-apm-traceparent header
ok 3 traceparent header has matching version
ok 4 traceparent header has matching traceId
ok 5 traceparent header has valid id
ok 6 traceparent header has matching flags
ok 7 has one transaction
ok 8 has one span
ok 9 has expected span name
ok 10 should be strictly equal
ok 11 should be deeply equivalent
ok 12 span.context.service.target
ok 13 span.context.destination
# http.request(options, callback)
ok 14 should have traceparent header
ok 15 should have elastic-apm-traceparent header
ok 16 traceparent header has matching version
ok 17 traceparent header has matching traceId
ok 18 traceparent header has valid id
ok 19 traceparent header has matching flags
ok 20 has one transaction
ok 21 has one span
ok 22 has expected span name
ok 23 should be strictly equal
ok 24 should be deeply equivalent
ok 25 span.context.service.target
ok 26 span.context.destination
# http: consider useElasticTraceparentHeader config option
ok 27 should have traceparent header
ok 28 should be strictly equal
ok 29 traceparent header has matching version
ok 30 traceparent header has matching traceId
ok 31 traceparent header has valid id
ok 32 traceparent header has matching flags
ok 33 has one transaction
ok 34 has one span
ok 35 has expected span name
ok 36 should be strictly equal
ok 37 should be deeply equivalent
ok 38 span.context.service.target
ok 39 span.context.destination
# http.request(options, callback) - aborted before socket
ok 40 has one transaction
ok 41 has one span
ok 42 has expected span name
ok 43 should be strictly equal
ok 44 should be deeply equivalent
ok 45 span.context.service.target
ok 46 span.context.destination
# http.request(options, callback) - aborted on socket
ok 47 has one transaction
ok 48 has one span
ok 49 has expected span name
ok 50 should be strictly equal
ok 51 should be deeply equivalent
ok 52 span.context.service.target
ok 53 span.context.destination
# http.request(options, callback) - aborted on data
ok 54 has one transaction
ok 55 has one span
ok 56 has expected span name
ok 57 should be strictly equal
ok 58 should be deeply equivalent
ok 59 span.context.service.target
ok 60 span.context.destination
# http.request(urlString)
ok 61 should have traceparent header
ok 62 should have elastic-apm-traceparent header
ok 63 traceparent header has matching version
ok 64 traceparent header has matching traceId
ok 65 traceparent header has valid id
ok 66 traceparent header has matching flags
ok 67 has one transaction
ok 68 has one span
ok 69 has expected span name
ok 70 should be strictly equal
ok 71 should be deeply equivalent
ok 72 span.context.service.target
ok 73 span.context.destination
# http.request(urlString, callback)
ok 74 should have traceparent header
ok 75 should have elastic-apm-traceparent header
ok 76 traceparent header has matching version
ok 77 traceparent header has matching traceId
ok 78 traceparent header has valid id
ok 79 traceparent header has matching flags
ok 80 has one transaction
ok 81 has one span
ok 82 has expected span name
ok 83 should be strictly equal
ok 84 should be deeply equivalent
ok 85 span.context.service.target
ok 86 span.context.destination
# http.request(urlObject)
ok 87 should have traceparent header
ok 88 should have elastic-apm-traceparent header
ok 89 traceparent header has matching version
ok 90 traceparent header has matching traceId
ok 91 traceparent header has valid id
ok 92 traceparent header has matching flags
ok 93 has one transaction
ok 94 has one span
ok 95 has expected span name
ok 96 should be strictly equal
ok 97 should be deeply equivalent
ok 98 span.context.service.target
ok 99 span.context.destination
# http.request(urlObject, callback)
ok 100 should have traceparent header
ok 101 should have elastic-apm-traceparent header
ok 102 traceparent header has matching version
ok 103 traceparent header has matching traceId
ok 104 traceparent header has valid id
ok 105 traceparent header has matching flags
ok 106 has one transaction
ok 107 has one span
ok 108 has expected span name
ok 109 should be strictly equal
ok 110 should be deeply equivalent
ok 111 span.context.service.target
ok 112 span.context.destination
# http.get(urlString)
ok 113 should have traceparent header
ok 114 should have elastic-apm-traceparent header
ok 115 traceparent header has matching version
ok 116 traceparent header has matching traceId
ok 117 traceparent header has valid id
ok 118 traceparent header has matching flags
ok 119 has one transaction
ok 120 has one span
ok 121 has expected span name
ok 122 should be strictly equal
ok 123 should be deeply equivalent
ok 124 span.context.service.target
ok 125 span.context.destination
# http.get(urlString, callback)
ok 126 should have traceparent header
ok 127 should have elastic-apm-traceparent header
ok 128 traceparent header has matching version
ok 129 traceparent header has matching traceId
ok 130 traceparent header has valid id
ok 131 traceparent header has matching flags
ok 132 has one transaction
ok 133 has one span
ok 134 has expected span name
ok 135 should be strictly equal
ok 136 should be deeply equivalent
ok 137 span.context.service.target
ok 138 span.context.destination
# http.get(urlObject)
ok 139 should have traceparent header
ok 140 should have elastic-apm-traceparent header
ok 141 traceparent header has matching version
ok 142 traceparent header has matching traceId
ok 143 traceparent header has valid id
ok 144 traceparent header has matching flags
ok 145 has one transaction
ok 146 has one span
ok 147 has expected span name
ok 148 should be strictly equal
ok 149 should be deeply equivalent
ok 150 span.context.service.target
ok 151 span.context.destination
# http.get(urlObject, callback)
ok 152 should have traceparent header
ok 153 should have elastic-apm-traceparent header
ok 154 traceparent header has matching version
ok 155 traceparent header has matching traceId
ok 156 traceparent header has valid id
ok 157 traceparent header has matching flags
ok 158 has one transaction
ok 159 has one span
ok 160 has expected span name
ok 161 should be strictly equal
ok 162 should be deeply equivalent
ok 163 span.context.service.target
ok 164 span.context.destination
# http.request(urlStringWithAuth, cb)
ok 165 authorization header
# http.request(..., bogusCb) errors on the bogusCb
not ok 166 http.request(..., bogusCb) errors on the bogusCb timed out after 5000ms
  ---
    operator: fail
    stack: |-
      Error: http.request(..., bogusCb) errors on the bogusCb timed out after 5000ms
          at Test.assert [as _assert] (/Users/trentm/el/apm-agent-nodejs2/node_modules/tape/lib/test.js:312:48)
          at Test.bound [as _assert] (/Users/trentm/el/apm-agent-nodejs2/node_modules/tape/lib/test.js:95:17)
          at Test.fail (/Users/trentm/el/apm-agent-nodejs2/node_modules/tape/lib/test.js:406:7)
          at Test.bound [as fail] (/Users/trentm/el/apm-agent-nodejs2/node_modules/tape/lib/test.js:95:17)
          at Timeout._onTimeout (/Users/trentm/el/apm-agent-nodejs2/node_modules/tape/lib/test.js:180:8)
          at listOnTimeout (node:internal/timers:573:17)
          at process.processTimers (node:internal/timers:514:7)
  ...
# https.request(options)
ok 167 should have traceparent header
ok 168 should have elastic-apm-traceparent header
ok 169 traceparent header has matching version
ok 170 traceparent header has matching traceId
ok 171 traceparent header has valid id
ok 172 traceparent header has matching flags
ok 173 has one transaction
ok 174 has one span
ok 175 has expected span name
ok 176 should be strictly equal
ok 177 should be deeply equivalent
ok 178 span.context.service.target
ok 179 span.context.destination
# https.request(options, callback)
ok 180 should have traceparent header
ok 181 should have elastic-apm-traceparent header
ok 182 traceparent header has matching version
ok 183 traceparent header has matching traceId
ok 184 traceparent header has valid id
ok 185 traceparent header has matching flags
ok 186 has one transaction
ok 187 has one span
ok 188 has expected span name
ok 189 should be strictly equal
ok 190 should be deeply equivalent
ok 191 span.context.service.target
ok 192 span.context.destination
# https: consider useElasticTraceparentHeader config option
ok 193 should have traceparent header
ok 194 should be strictly equal
ok 195 traceparent header has matching version
ok 196 traceparent header has matching traceId
ok 197 traceparent header has valid id
ok 198 traceparent header has matching flags
ok 199 has one transaction
ok 200 has one span
ok 201 has expected span name
ok 202 should be strictly equal
ok 203 should be deeply equivalent
ok 204 span.context.service.target
ok 205 span.context.destination
# https.request(urlString, options)
ok 206 should have traceparent header
ok 207 should have elastic-apm-traceparent header
ok 208 traceparent header has matching version
ok 209 traceparent header has matching traceId
ok 210 traceparent header has valid id
ok 211 traceparent header has matching flags
ok 212 has one transaction
ok 213 has one span
ok 214 has expected span name
ok 215 should be strictly equal
ok 216 should be deeply equivalent
ok 217 span.context.service.target
ok 218 span.context.destination
# https.request(urlString, options, callback)
ok 219 should have traceparent header
ok 220 should have elastic-apm-traceparent header
ok 221 traceparent header has matching version
ok 222 traceparent header has matching traceId
ok 223 traceparent header has valid id
ok 224 traceparent header has matching flags
ok 225 has one transaction
ok 226 has one span
ok 227 has expected span name
ok 228 should be strictly equal
ok 229 should be deeply equivalent
ok 230 span.context.service.target
ok 231 span.context.destination
# https.request(urlObject, options)
ok 232 should have traceparent header
ok 233 should have elastic-apm-traceparent header
ok 234 traceparent header has matching version
ok 235 traceparent header has matching traceId
ok 236 traceparent header has valid id
ok 237 traceparent header has matching flags
ok 238 has one transaction
ok 239 has one span
ok 240 has expected span name
ok 241 should be strictly equal
ok 242 should be deeply equivalent
ok 243 span.context.service.target
ok 244 span.context.destination
# https.request(urlObject, options, callback)
ok 245 should have traceparent header
ok 246 should have elastic-apm-traceparent header
ok 247 traceparent header has matching version
ok 248 traceparent header has matching traceId
ok 249 traceparent header has valid id
ok 250 traceparent header has matching flags
ok 251 has one transaction
ok 252 has one span
ok 253 has expected span name
ok 254 should be strictly equal
ok 255 should be deeply equivalent
ok 256 span.context.service.target
ok 257 span.context.destination
# https.get(urlString, options)
ok 258 should have traceparent header
ok 259 should have elastic-apm-traceparent header
ok 260 traceparent header has matching version
ok 261 traceparent header has matching traceId
ok 262 traceparent header has valid id
ok 263 traceparent header has matching flags
ok 264 has one transaction
ok 265 has one span
ok 266 has expected span name
ok 267 should be strictly equal
ok 268 should be deeply equivalent
ok 269 span.context.service.target
ok 270 span.context.destination
# https.get(urlString, options, callback)
ok 271 should have traceparent header
ok 272 should have elastic-apm-traceparent header
ok 273 traceparent header has matching version
ok 274 traceparent header has matching traceId
ok 275 traceparent header has valid id
ok 276 traceparent header has matching flags
ok 277 has one transaction
ok 278 has one span
ok 279 has expected span name
ok 280 should be strictly equal
ok 281 should be deeply equivalent
ok 282 span.context.service.target
ok 283 span.context.destination
# https.get(urlObject, options)
ok 284 should have traceparent header
ok 285 should have elastic-apm-traceparent header
ok 286 traceparent header has matching version
ok 287 traceparent header has matching traceId
ok 288 traceparent header has valid id
ok 289 traceparent header has matching flags
ok 290 has one transaction
ok 291 has one span
ok 292 has expected span name
ok 293 should be strictly equal
ok 294 should be deeply equivalent
ok 295 span.context.service.target
ok 296 span.context.destination
# https.get(urlObject, options, callback)
ok 297 should have traceparent header
ok 298 should have elastic-apm-traceparent header
ok 299 traceparent header has matching version
ok 300 traceparent header has matching traceId
ok 301 traceparent header has valid id
ok 302 traceparent header has matching flags
ok 303 has one transaction
ok 304 has one span
ok 305 has expected span name
ok 306 should be strictly equal
ok 307 should be deeply equivalent
ok 308 span.context.service.target
ok 309 span.context.destination

/Users/trentm/el/apm-agent-nodejs2/test/_mock_http_client.js:47
      else if (this._writes.length > expected) throw new Error('too many writes')
                                               ^

Error: too many writes
    at Object._write (/Users/trentm/el/apm-agent-nodejs2/test/_mock_http_client.js:47:54)
    at Object.sendSpan (/Users/trentm/el/apm-agent-nodejs2/test/_mock_http_client.js:50:12)
    at /Users/trentm/el/apm-agent-nodejs2/lib/instrumentation/index.js:473:28
    at done (/Users/trentm/el/apm-agent-nodejs2/lib/instrumentation/span.js:486:5)
    at process.processTicksAndRejections (node:internal/process/task_queues:77:11)

Node.js v20.0.0-nightly202304102d1934aa96

The text was updated successfully, but these errors were encountered:

… v20 Fixes: #3261

trentm · 2023-04-12T00:23:59Z

The same test fails with node v19.9.0 (released a few days ago).

...
# http.request(..., bogusCb) errors on the bogusCb
not ok 166 http.request(..., bogusCb) errors on the bogusCb timed out after 5000ms
  ---
    operator: fail
    stack: |-
      Error: http.request(..., bogusCb) errors on the bogusCb timed out after 5000ms
          at Test.assert [as _assert] (/Users/trentm/el/apm-agent-nodejs/node_modules/tape/lib/test.js:312:48)
          at Test.bound [as _assert] (/Users/trentm/el/apm-agent-nodejs/node_modules/tape/lib/test.js:95:17)
          at Test.fail (/Users/trentm/el/apm-agent-nodejs/node_modules/tape/lib/test.js:406:7)
          at Test.bound [as fail] (/Users/trentm/el/apm-agent-nodejs/node_modules/tape/lib/test.js:95:17)
          at Timeout._onTimeout (/Users/trentm/el/apm-agent-nodejs/node_modules/tape/lib/test.js:180:8)
          at listOnTimeout (node:internal/timers:573:17)
          at process.processTimers (node:internal/timers:514:7)
  ...
...
# https.get(urlObject, options, callback)
ok 297 should have traceparent header
ok 298 should have elastic-apm-traceparent header
ok 299 traceparent header has matching version
ok 300 traceparent header has matching traceId
ok 301 traceparent header has valid id
ok 302 traceparent header has matching flags
ok 303 has one transaction
ok 304 has one span
ok 305 has expected span name
ok 306 should be strictly equal
ok 307 should be deeply equivalent
ok 308 span.context.service.target
ok 309 span.context.destination
/Users/trentm/el/apm-agent-nodejs/test/_mock_http_client.js:47
      else if (this._writes.length > expected) throw new Error('too many writes')
                                               ^

Error: too many writes
    at Object._write (/Users/trentm/el/apm-agent-nodejs/test/_mock_http_client.js:47:54)
    at Object.sendSpan (/Users/trentm/el/apm-agent-nodejs/test/_mock_http_client.js:50:12)
    at /Users/trentm/el/apm-agent-nodejs/lib/instrumentation/index.js:473:28
    at done (/Users/trentm/el/apm-agent-nodejs/lib/instrumentation/span.js:486:5)
    at process.processTicksAndRejections (node:internal/process/task_queues:77:11)

Node.js v19.9.0

Full test run output

% node --version
v19.9.0


% node test/instrumentation/modules/http/outgoing.test.js
TAP version 13
# http.request(options)
ok 1 should have traceparent header
ok 2 should have elastic-apm-traceparent header
ok 3 traceparent header has matching version
ok 4 traceparent header has matching traceId
ok 5 traceparent header has valid id
ok 6 traceparent header has matching flags
ok 7 has one transaction
ok 8 has one span
ok 9 has expected span name
ok 10 should be strictly equal
ok 11 should be deeply equivalent
ok 12 span.context.service.target
ok 13 span.context.destination
# http.request(options, callback)
ok 14 should have traceparent header
ok 15 should have elastic-apm-traceparent header
ok 16 traceparent header has matching version
ok 17 traceparent header has matching traceId
ok 18 traceparent header has valid id
ok 19 traceparent header has matching flags
ok 20 has one transaction
ok 21 has one span
ok 22 has expected span name
ok 23 should be strictly equal
ok 24 should be deeply equivalent
ok 25 span.context.service.target
ok 26 span.context.destination
# http: consider useElasticTraceparentHeader config option
ok 27 should have traceparent header
ok 28 should be strictly equal
ok 29 traceparent header has matching version
ok 30 traceparent header has matching traceId
ok 31 traceparent header has valid id
ok 32 traceparent header has matching flags
ok 33 has one transaction
ok 34 has one span
ok 35 has expected span name
ok 36 should be strictly equal
ok 37 should be deeply equivalent
ok 38 span.context.service.target
ok 39 span.context.destination
# http.request(options, callback) - aborted before socket
ok 40 has one transaction
ok 41 has one span
ok 42 has expected span name
ok 43 should be strictly equal
ok 44 should be deeply equivalent
ok 45 span.context.service.target
ok 46 span.context.destination
# http.request(options, callback) - aborted on socket
ok 47 has one transaction
ok 48 has one span
ok 49 has expected span name
ok 50 should be strictly equal
ok 51 should be deeply equivalent
ok 52 span.context.service.target
ok 53 span.context.destination
# http.request(options, callback) - aborted on data
ok 54 has one transaction
ok 55 has one span
ok 56 has expected span name
ok 57 should be strictly equal
ok 58 should be deeply equivalent
ok 59 span.context.service.target
ok 60 span.context.destination
# http.request(urlString)
ok 61 should have traceparent header
ok 62 should have elastic-apm-traceparent header
ok 63 traceparent header has matching version
ok 64 traceparent header has matching traceId
ok 65 traceparent header has valid id
ok 66 traceparent header has matching flags
ok 67 has one transaction
ok 68 has one span
ok 69 has expected span name
ok 70 should be strictly equal
ok 71 should be deeply equivalent
ok 72 span.context.service.target
ok 73 span.context.destination
# http.request(urlString, callback)
ok 74 should have traceparent header
ok 75 should have elastic-apm-traceparent header
ok 76 traceparent header has matching version
ok 77 traceparent header has matching traceId
ok 78 traceparent header has valid id
ok 79 traceparent header has matching flags
ok 80 has one transaction
ok 81 has one span
ok 82 has expected span name
ok 83 should be strictly equal
ok 84 should be deeply equivalent
ok 85 span.context.service.target
ok 86 span.context.destination
# http.request(urlObject)
ok 87 should have traceparent header
ok 88 should have elastic-apm-traceparent header
ok 89 traceparent header has matching version
ok 90 traceparent header has matching traceId
ok 91 traceparent header has valid id
ok 92 traceparent header has matching flags
ok 93 has one transaction
ok 94 has one span
ok 95 has expected span name
ok 96 should be strictly equal
ok 97 should be deeply equivalent
ok 98 span.context.service.target
ok 99 span.context.destination
# http.request(urlObject, callback)
ok 100 should have traceparent header
ok 101 should have elastic-apm-traceparent header
ok 102 traceparent header has matching version
ok 103 traceparent header has matching traceId
ok 104 traceparent header has valid id
ok 105 traceparent header has matching flags
ok 106 has one transaction
ok 107 has one span
ok 108 has expected span name
ok 109 should be strictly equal
ok 110 should be deeply equivalent
ok 111 span.context.service.target
ok 112 span.context.destination
# http.get(urlString)
ok 113 should have traceparent header
ok 114 should have elastic-apm-traceparent header
ok 115 traceparent header has matching version
ok 116 traceparent header has matching traceId
ok 117 traceparent header has valid id
ok 118 traceparent header has matching flags
ok 119 has one transaction
ok 120 has one span
ok 121 has expected span name
ok 122 should be strictly equal
ok 123 should be deeply equivalent
ok 124 span.context.service.target
ok 125 span.context.destination
# http.get(urlString, callback)
ok 126 should have traceparent header
ok 127 should have elastic-apm-traceparent header
ok 128 traceparent header has matching version
ok 129 traceparent header has matching traceId
ok 130 traceparent header has valid id
ok 131 traceparent header has matching flags
ok 132 has one transaction
ok 133 has one span
ok 134 has expected span name
ok 135 should be strictly equal
ok 136 should be deeply equivalent
ok 137 span.context.service.target
ok 138 span.context.destination
# http.get(urlObject)
ok 139 should have traceparent header
ok 140 should have elastic-apm-traceparent header
ok 141 traceparent header has matching version
ok 142 traceparent header has matching traceId
ok 143 traceparent header has valid id
ok 144 traceparent header has matching flags
ok 145 has one transaction
ok 146 has one span
ok 147 has expected span name
ok 148 should be strictly equal
ok 149 should be deeply equivalent
ok 150 span.context.service.target
ok 151 span.context.destination
# http.get(urlObject, callback)
ok 152 should have traceparent header
ok 153 should have elastic-apm-traceparent header
ok 154 traceparent header has matching version
ok 155 traceparent header has matching traceId
ok 156 traceparent header has valid id
ok 157 traceparent header has matching flags
ok 158 has one transaction
ok 159 has one span
ok 160 has expected span name
ok 161 should be strictly equal
ok 162 should be deeply equivalent
ok 163 span.context.service.target
ok 164 span.context.destination
# http.request(urlStringWithAuth, cb)
ok 165 authorization header
# http.request(..., bogusCb) errors on the bogusCb
not ok 166 http.request(..., bogusCb) errors on the bogusCb timed out after 5000ms
  ---
    operator: fail
    stack: |-
      Error: http.request(..., bogusCb) errors on the bogusCb timed out after 5000ms
          at Test.assert [as _assert] (/Users/trentm/el/apm-agent-nodejs/node_modules/tape/lib/test.js:312:48)
          at Test.bound [as _assert] (/Users/trentm/el/apm-agent-nodejs/node_modules/tape/lib/test.js:95:17)
          at Test.fail (/Users/trentm/el/apm-agent-nodejs/node_modules/tape/lib/test.js:406:7)
          at Test.bound [as fail] (/Users/trentm/el/apm-agent-nodejs/node_modules/tape/lib/test.js:95:17)
          at Timeout._onTimeout (/Users/trentm/el/apm-agent-nodejs/node_modules/tape/lib/test.js:180:8)
          at listOnTimeout (node:internal/timers:573:17)
          at process.processTimers (node:internal/timers:514:7)
  ...
# https.request(options)
ok 167 should have traceparent header
ok 168 should have elastic-apm-traceparent header
ok 169 traceparent header has matching version
ok 170 traceparent header has matching traceId
ok 171 traceparent header has valid id
ok 172 traceparent header has matching flags
ok 173 has one transaction
ok 174 has one span
ok 175 has expected span name
ok 176 should be strictly equal
ok 177 should be deeply equivalent
ok 178 span.context.service.target
ok 179 span.context.destination
# https.request(options, callback)
ok 180 should have traceparent header
ok 181 should have elastic-apm-traceparent header
ok 182 traceparent header has matching version
ok 183 traceparent header has matching traceId
ok 184 traceparent header has valid id
ok 185 traceparent header has matching flags
ok 186 has one transaction
ok 187 has one span
ok 188 has expected span name
ok 189 should be strictly equal
ok 190 should be deeply equivalent
ok 191 span.context.service.target
ok 192 span.context.destination
# https: consider useElasticTraceparentHeader config option
ok 193 should have traceparent header
ok 194 should be strictly equal
ok 195 traceparent header has matching version
ok 196 traceparent header has matching traceId
ok 197 traceparent header has valid id
ok 198 traceparent header has matching flags
ok 199 has one transaction
ok 200 has one span
ok 201 has expected span name
ok 202 should be strictly equal
ok 203 should be deeply equivalent
ok 204 span.context.service.target
ok 205 span.context.destination
# https.request(urlString, options)
ok 206 should have traceparent header
ok 207 should have elastic-apm-traceparent header
ok 208 traceparent header has matching version
ok 209 traceparent header has matching traceId
ok 210 traceparent header has valid id
ok 211 traceparent header has matching flags
ok 212 has one transaction
ok 213 has one span
ok 214 has expected span name
ok 215 should be strictly equal
ok 216 should be deeply equivalent
ok 217 span.context.service.target
ok 218 span.context.destination
# https.request(urlString, options, callback)
ok 219 should have traceparent header
ok 220 should have elastic-apm-traceparent header
ok 221 traceparent header has matching version
ok 222 traceparent header has matching traceId
ok 223 traceparent header has valid id
ok 224 traceparent header has matching flags
ok 225 has one transaction
ok 226 has one span
ok 227 has expected span name
ok 228 should be strictly equal
ok 229 should be deeply equivalent
ok 230 span.context.service.target
ok 231 span.context.destination
# https.request(urlObject, options)
ok 232 should have traceparent header
ok 233 should have elastic-apm-traceparent header
ok 234 traceparent header has matching version
ok 235 traceparent header has matching traceId
ok 236 traceparent header has valid id
ok 237 traceparent header has matching flags
ok 238 has one transaction
ok 239 has one span
ok 240 has expected span name
ok 241 should be strictly equal
ok 242 should be deeply equivalent
ok 243 span.context.service.target
ok 244 span.context.destination
# https.request(urlObject, options, callback)
ok 245 should have traceparent header
ok 246 should have elastic-apm-traceparent header
ok 247 traceparent header has matching version
ok 248 traceparent header has matching traceId
ok 249 traceparent header has valid id
ok 250 traceparent header has matching flags
ok 251 has one transaction
ok 252 has one span
ok 253 has expected span name
ok 254 should be strictly equal
ok 255 should be deeply equivalent
ok 256 span.context.service.target
ok 257 span.context.destination
# https.get(urlString, options)
ok 258 should have traceparent header
ok 259 should have elastic-apm-traceparent header
ok 260 traceparent header has matching version
ok 261 traceparent header has matching traceId
ok 262 traceparent header has valid id
ok 263 traceparent header has matching flags
ok 264 has one transaction
ok 265 has one span
ok 266 has expected span name
ok 267 should be strictly equal
ok 268 should be deeply equivalent
ok 269 span.context.service.target
ok 270 span.context.destination
# https.get(urlString, options, callback)
ok 271 should have traceparent header
ok 272 should have elastic-apm-traceparent header
ok 273 traceparent header has matching version
ok 274 traceparent header has matching traceId
ok 275 traceparent header has valid id
ok 276 traceparent header has matching flags
ok 277 has one transaction
ok 278 has one span
ok 279 has expected span name
ok 280 should be strictly equal
ok 281 should be deeply equivalent
ok 282 span.context.service.target
ok 283 span.context.destination
# https.get(urlObject, options)
ok 284 should have traceparent header
ok 285 should have elastic-apm-traceparent header
ok 286 traceparent header has matching version
ok 287 traceparent header has matching traceId
ok 288 traceparent header has valid id
ok 289 traceparent header has matching flags
ok 290 has one transaction
ok 291 has one span
ok 292 has expected span name
ok 293 should be strictly equal
ok 294 should be deeply equivalent
ok 295 span.context.service.target
ok 296 span.context.destination
# https.get(urlObject, options, callback)
ok 297 should have traceparent header
ok 298 should have elastic-apm-traceparent header
ok 299 traceparent header has matching version
ok 300 traceparent header has matching traceId
ok 301 traceparent header has valid id
ok 302 traceparent header has matching flags
ok 303 has one transaction
ok 304 has one span
ok 305 has expected span name
ok 306 should be strictly equal
ok 307 should be deeply equivalent
ok 308 span.context.service.target
ok 309 span.context.destination
/Users/trentm/el/apm-agent-nodejs/test/_mock_http_client.js:47
      else if (this._writes.length > expected) throw new Error('too many writes')
                                               ^

Error: too many writes
    at Object._write (/Users/trentm/el/apm-agent-nodejs/test/_mock_http_client.js:47:54)
    at Object.sendSpan (/Users/trentm/el/apm-agent-nodejs/test/_mock_http_client.js:50:12)
    at /Users/trentm/el/apm-agent-nodejs/lib/instrumentation/index.js:473:28
    at done (/Users/trentm/el/apm-agent-nodejs/lib/instrumentation/span.js:486:5)
    at process.processTicksAndRejections (node:internal/process/task_queues:77:11)

Node.js v19.9.0

trentm · 2023-04-12T00:29:55Z

The issue is that:

in both node v19.9.0 and recent node v20 nightly builds the url.urlToHttpOptions() changed such that the return value results in isURL(options) === true -- where isURL is the internal test function in "node/lib/internal/url.js".
This combined with the instrumentation of http.request here (https://github.com/elastic/apm-agent-nodejs/blob/v3.44.1/lib/instrumentation/http-shared.js#L158-L228) that converts the function input arguments and expects to call the http.request(options, callback) function signature form. If that options argument results in isURL(options) === true, then the second argument (the callback) will be treated like an options argument if it isn't a function.

The net result was that calling http.request(<a-url-or-url-string>, "a bogus callback") changed behaviour with the APM agent's instrumentation.

… v20 (#3265) Fixes: #3261

trentm added the 8.9-candidate label Apr 10, 2023

github-actions bot added the agent-nodejs Make available for APM Agents project planning. label Apr 10, 2023

trentm changed the title ~~http/outgoing.test.js test failures with latest node v20~~ http/outgoing.test.js test failures with latest node v20 and v19.9.0 Apr 11, 2023

trentm added a commit that referenced this issue Apr 12, 2023

fix: edge case in instr of http.request() et al with node v19.9.0 and…

cb22257

… v20 Fixes: #3261

trentm mentioned this issue Apr 12, 2023

fix: edge case in instr of http.request() et al with node v19.9.0 and v20 #3265

Merged

trentm closed this as completed in #3265 Apr 12, 2023

trentm added a commit that referenced this issue Apr 12, 2023

fix: edge case in instr of http.request() et al with node v19.9.0 and…

bea0ac5

… v20 (#3265) Fixes: #3261

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

http/outgoing.test.js test failures with latest node v20 and v19.9.0 #3261

http/outgoing.test.js test failures with latest node v20 and v19.9.0 #3261

trentm commented Apr 10, 2023

trentm commented Apr 12, 2023 •

edited

trentm commented Apr 12, 2023

http/outgoing.test.js test failures with latest node v20 and v19.9.0 #3261

http/outgoing.test.js test failures with latest node v20 and v19.9.0 #3261

Comments

trentm commented Apr 10, 2023

trentm commented Apr 12, 2023 • edited

trentm commented Apr 12, 2023

trentm commented Apr 12, 2023 •

edited