test-npm failing on master after introduction of initial async hooks implementation

[mscdex]

• Version: master
• Platform: n/a
• Subsystem: async_hooks

make test-npm is failing since #12892 (4a7233c) landed it seems. In particular, it appears that it's possible for a socket handle to not have an asyncReset function attached (perhaps something in npm or one of its dependencies are unsetting it?), causing a TypeError on this line.

After running across that issue, I spotted just a few lines below that that there is a bug waiting to happen on this line and this line because newSocket should be undefined if an error occurred.

I have not checked for other similar potential issues yet.

/cc @AndreasMadsen @addaleax @trevnorris

[refack]

I'll try to distill this into a test case.

[Fishrock123]

Hmmm, this is not new.

I debugged this 2-3 times with @trevnorris over the course of Async Hooks' development. I was pretty sure it was fixed, though.

[trevnorris]

I've run into this elsewhere. Thought I traced through core code well enough to be confident those checks could be removed, but apparently that's not the case. Only way I've found that can definitely mitigate this issue is to check if the call is actually a function. If someone has a better idea I'm all ears. Otherwise I can write up a PR to fix this.

[AndreasMadsen]

@trevnorris what causes the issue?

[trevnorris]

@AndreasMadsen from what I've seen it usually happens when users fake the _handle, but in this case it can also be from a user supplied Agent instance that isn't attached to an internal node resource.

[refack]

I have an almost minimal (depends on request) failing test:

'use strict'
var https = require('https')
var request = require('request')
var opt = {
  agent: new https.Agent({
    'keepAlive': true,
    'maxSockets': 50,
    'rejectUnauthorized': true,
  }),
  uri: 'https://www.google.com/'
}

request(opt, (error, response, data) => {
  console.log(`error: ${error}`)
  console.log(`response: ${response}`)
  console.log(`data.length: ${data && data.length}`)
  request(opt, (error, response, data) => {
    console.log(`error: ${error}`)
    console.log(`response: ${response}`)
  console.log(`data.length: ${data && data.length}`)
  });
});

Still request uses the Agent better then I managed...

[refack]

@trevnorris question: in 7e3a3c9 why did only tcp_wrap get a asyncReset JS function?

After running across that issue, I spotted just a few lines below that that there is a bug waiting to happen on this line and this line because newSocket should be undefined if an error occurred.

P.S. @mscdex those cases work, newSocket is created (didn't think of the err case... midnight brain 😴 )

[mscdex]

After running across that issue, I spotted just a few lines below that that there is a bug waiting to happen on this line and this line because newSocket should be undefined if an error occurred.

P.S. @mscdex those cases work, newSocket is created

@refack That's not true. Custom async createConnection() implementations can pass an error and in that case there is no socket.

[refack]

@refack That's not true. Custom async createConnection() implementations can pass an error and in that case there is no socket.

Gottcha... 👍

[refack]

minimal failing test

'use strict'
var https = require('https')
var options = {
  agent: new https.Agent({
    'keepAlive': true,
    'maxSockets': 50,
    'rejectUnauthorized': true,
  }),
  hostname: 'encrypted.google.com',
  port: 443,
  path: '/',
  method: 'GET'
}

const req = https.request(options, (res) => {
  console.log('statusCode:', res.statusCode)

  res.on('error', (e) => {
    console.error(e)
  })

  let ret = ''
  res.on('data', (d) => { ret += d })

  res.socket.on('free', (hadErr) => {
    console.log(`hadErr ${hadErr}`)
    console.log(`ret.length ${ret.length}`)

    const req2 = https.request(options)
  })
})

req.end();

Output

statusCode: 200
hadErr undefined
ret.length 41688
_http_agent.js:170
    socket._handle.asyncReset();
                   ^

TypeError: socket._handle.asyncReset is not a function
    at Agent.addRequest (_http_agent.js:170:20)
    at new ClientRequest (_http_client.js:269:16)
    at Object.request (http.js:39:10)
    at Object.request (https.js:230:15)
    at TLSSocket.res.socket.on (D:\code\tools\tmp\test-utl.js:29:24)
    at emitNone (events.js:110:20)
    at TLSSocket.emit (events.js:207:7)
    at emitFreeNT (_http_client.js:621:10)
    at _combinedTickCallback (internal/process/next_tick.js:99:11)
    at process._tickCallback (internal/process/next_tick.js:161:9)

Process finished with exit code 1

IMHO since it's a TLS connection, the Agent tries to reuse a TLSSocket, and the TLSWrap doesn't have an asyncReset method

[mscdex]

The second part of this issue seems to still exist and was not solved by #13092. We now have users hitting that issue: #13831

[mscdex]

/cc @nodejs/async_hooks

[refack]

There was further discussion on the "broken" Agent story in #13548 (comment)