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

@AndreasMadsen

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

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

@trevnorris

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.

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.

@trevnorris

@trevnorris what causes the issue?

@AndreasMadsen

@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.

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...

@trevnorris

@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... 👍

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

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

/cc @nodejs/async_hooks

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

http: guard against failed sockets creation

Navigation Menu

Repository navigation

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

minimal failing test

Output

3 remaining items

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

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

Description

Activity

refack commented on May 16, 2017

Fishrock123 commented on May 16, 2017

trevnorris commented on May 17, 2017

AndreasMadsen commented on May 17, 2017

trevnorris commented on May 18, 2017

refack commented on May 18, 2017

refack commented on May 18, 2017

mscdex commented on May 18, 2017

refack commented on May 18, 2017

refack commented on May 18, 2017

minimal failing test

Output

3 remaining items

mscdex commented on Jun 21, 2017

mscdex commented on Jun 21, 2017

refack commented on Jun 21, 2017

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions