Unref the socket for a cleaner exit

[DiegoRBaquero]

After hours of trying to figure it out and falling sleeping, I woke up and got the solution.

Related: socketio/engine.io-client#528

[lpinca]

What is the issue fixed by this? Can you create a test case which shows what is wrong?
Thanks.

[DiegoRBaquero]

@lpinca Even after closing using .close() and .terminate() and unrefing the library itself, the TCP socket remains open. The log in socketio/engine.io-client#528 points to it.

I made sure engine.io-client was calling the terminate() and .close functions. attached onclose listener is even called twice by ws.

If the socket is the only active socket in the system and nothing else is ref'd then the program will exit normally, as expected: https://nodejs.org/api/net.html#net_socket_unref

[DiegoRBaquero]

It will also help for this issue, if the socket is the only thing keeping the process from exiting because of the timeout: #891

[lpinca]

@DiegoRBaquero are you able to create a test case using nothing but ws? Thank you.

[DiegoRBaquero]

@lpinca Sorry, I haven't really learned to use Mocha. All your test cases call done function on onClose (which is triggered), so Mocha will exit anyways.

Is there a con by unrefing the socket?

[lpinca]

You don't have to use mocha, just put a piece of code here which reproduces the issue.
I think that using socket.unref() will only hide the real issue, the socket should be closed or destroyed and freed automatically.

I would like to see a piece of code which reproduces the issue in order to investigate where the real issue is.

[DiegoRBaquero]

@lpinca Didn't manage to reproduce using ws only.

The last line called is this._socket.end(); at:

Trace: Clean WS Rsrcs f
    at WebSocket.cleanupWebsocketResources (/XXXXXXX/node_modules/ws/lib/WebSocket.js:993:17)
    at emitNone (events.js:91:20)
    at Socket.emit (events.js:185:7)
    at endReadableNT (_stream_readable.js:974:12)
    at _combinedTickCallback (internal/process/next_tick.js:74:11)
    at process._tickCallback (internal/process/next_tick.js:98:9)

Where does cleanupWebsocketResources come from?

function cleanupWebsocketResources(error) {
  console.log('Clean WS Rsrcs')
  if (this.readyState === WebSocket.CLOSED) {
    console.log('Clean WS Rsrcs a')
    return;
  }

  this.readyState = WebSocket.CLOSED;

  clearTimeout(this._closeTimer);
  this._closeTimer = null;

  // If the connection was closed abnormally (with an error), or if
  // the close control frame was not received then the close code
  // must default to 1006.
  if (error || !this._closeReceived) {
    this._closeCode = 1006;
  }
  this.emit('close', this._closeCode || 1000, this._closeMessage || '');

  if (this._socket) {
    console.log('Clean WS Rsrcs b')
    if (this._ultron) {
      console.log('Clean WS Rsrcs c')
      this._ultron.destroy();
    }
    this._socket.on('error', function onerror() {
      console.log('Clean WS Rsrcs d')
      try { this.destroy(); }
      catch (e) {}
    });

    try {
      console.log('Clean WS Rsrcs e')
      if (!error) {
        console.trace('Clean WS Rsrcs f')
        this._socket.end();
      } else this._socket.destroy();
    } catch (e) { 
      console.error(e)
      /* Ignore termination errors */ 
    }

    this._socket = null;
    this._ultron = null;
  }

  if (this._sender) {
    this._sender.removeAllListeners();
    this._sender = null;
  }

  if (this._receiver) {
    this._receiver.cleanup();
    this._receiver = null;
  }

  if (this.extensions[PerMessageDeflate.extensionName]) {
    this.extensions[PerMessageDeflate.extensionName].cleanup();
  }

  this.extensions = null;

  this.removeAllListeners();
  this.on('error', function onerror() {}); // catch all errors after this
  delete this._queue;
}

Log:

transport close
Close called in ws
WS close c
Clean WS Rsrcs
onClose triggered by ws
Clean WS Rsrcs b
Clean WS Rsrcs c
Clean WS Rsrcs e
Clean WS Rsrcs f

The socket object at that point:

Socket {
  connecting: false,
  _hadError: false,
  _handle: null,
  _parent: null,
  _host: 'localhost',
  _readableState: 
   ReadableState {
     objectMode: false,
     highWaterMark: 16384,
     buffer: BufferList { head: null, tail: null, length: 0 },
     length: 0,
     pipes: null,
     pipesCount: 0,
     flowing: true,
     ended: true,
     endEmitted: true,
     reading: false,
     sync: false,
     needReadable: false,
     emittedReadable: false,
     readableListening: false,
     resumeScheduled: false,
     defaultEncoding: 'utf8',
     ranOut: false,
     awaitDrain: 0,
     readingMore: false,
     decoder: null,
     encoding: null },
  readable: false,
  domain: null,
  _events: 
   { end: [ [Object] ],
     finish: [Function: onSocketFinish],
     _socketEnd: [Function: onSocketEnd],
     drain: [Function: ondrain],
     error: [Function: onerror] },
  _eventsCount: 5,
  _maxListeners: undefined,
  _writableState: 
   WritableState {
     objectMode: false,
     highWaterMark: 16384,
     needDrain: false,
     ending: true,
     ended: true,
     finished: true,
     decodeStrings: false,
     defaultEncoding: 'utf8',
     length: 0,
     writing: false,
     corked: 0,
     sync: false,
     bufferProcessing: false,
     onwrite: [Function],
     writecb: null,
     writelen: 0,
     bufferedRequest: null,
     lastBufferedRequest: null,
     pendingcb: 0,
     prefinished: true,
     errorEmitted: false,
     bufferedRequestCount: 0,
     corkedRequestsFree: CorkedRequest { next: null, entry: null, finish: [Function] } },
  writable: false,
  allowHalfOpen: false,
  destroyed: true,
  _bytesDispatched: 311,
  _sockname: null,
  _pendingData: null,
  _pendingEncoding: '',
  server: null,
  _server: null,
  parser: null,
  _httpMessage: 
   ClientRequest {
     domain: null,
     _events: {},
     _eventsCount: 0,
     _maxListeners: undefined,
     output: [],
     outputEncodings: [],
     outputCallbacks: [],
     outputSize: 0,
     writable: true,
     _last: true,
     upgrading: true,
     chunkedEncoding: false,
     shouldKeepAlive: true,
     useChunkedEncodingByDefault: false,
     sendDate: false,
     _removedHeader: { connection: false },
     _contentLength: 0,
     _hasBody: true,
     _trailer: '',
     finished: true,
     _headerSent: true,
     socket: [Circular],
     connection: [Circular],
     _header: 'GET /engine.io/?EIO=3&transport=websocket&sid=PGiTgxbhbectev0-AAAT HTTP/1.1\r\nConnection: Upgrade\r\nUpgrade: websocket\r\nHost: localhost:3000\r\nSec-WebSocket-Version: 13\r\nSec-WebSocket-Key: MTMtMTQ4MzM4NzMwMzIzMA==\r\nSec-WebSocket-Extensions: permessage-deflate; client_max_window_bits\r\n\r\n',
     _headers: 
      { connection: 'Upgrade',
        upgrade: 'websocket',
        host: 'localhost:3000',
        'sec-websocket-version': 13,
        'sec-websocket-key': 'MTMtMTQ4MzM4NzMwMzIzMA==',
        'sec-websocket-extensions': 'permessage-deflate; client_max_window_bits' },
     _headerNames: 
      { connection: 'Connection',
        upgrade: 'Upgrade',
        host: 'Host',
        'sec-websocket-version': 'Sec-WebSocket-Version',
        'sec-websocket-key': 'Sec-WebSocket-Key',
        'sec-websocket-extensions': 'Sec-WebSocket-Extensions' },
     _onPendingData: null,
     agent: 
      Agent {
        domain: null,
        _events: [Object],
        _eventsCount: 1,
        _maxListeners: undefined,
        defaultPort: 80,
        protocol: 'http:',
        options: [Object],
        requests: {},
        sockets: {},
        freeSockets: {},
        keepAliveMsecs: 1000,
        keepAlive: false,
        maxSockets: Infinity,
        maxFreeSockets: 256 },
     socketPath: undefined,
     timeout: undefined,
     method: 'GET',
     path: '/engine.io/?EIO=3&transport=websocket&sid=PGiTgxbhbectev0-AAAT',
     _ended: false,
     parser: null,
     res: 
      IncomingMessage {
        _readableState: [Object],
        readable: true,
        domain: null,
        _events: {},
        _eventsCount: 0,
        _maxListeners: undefined,
        socket: [Circular],
        connection: [Circular],
        httpVersionMajor: 1,
        httpVersionMinor: 1,
        httpVersion: '1.1',
        complete: true,
        headers: [Object],
        rawHeaders: [Object],
        trailers: {},
        rawTrailers: [],
        upgrade: true,
        url: '',
        method: null,
        statusCode: 101,
        statusMessage: 'Switching Protocols',
        client: [Circular],
        _consuming: false,
        _dumped: false },
     upgradeOrConnect: true },
  read: [Function],
  _consuming: true,
  _idleNext: null,
  _idlePrev: null,
  _idleTimeout: -1,
  write: [Function: writeAfterFIN] }

[lpinca]

I see nothing wrong. A closing handshake is started when ws.close() is called. The other peer sends a TCP fin packet. When this packet is received cleanupWebsocketResources() is called which in turn calls this._socket.end(); to fully close the socket.

It seems a normal close procedure.

[DiegoRBaquero]

This looks like an issue on engine.io completely where the client closes the socket, send the FIN Packet but the client hangs.

On the server:

engine:transport onClose Called +2s
  engine:socket closing closed +0ms
  engine:socket woot +0ms
  engine:socket clearing transport +0ms
  engine:transport close +0ms // socket calls transport.close again
  engine:transport damn +0ms // Was already called, return
Socket closed // My callback

[lpinca]

I don't know but maybe the issue is in engine.io if it can't be reproduced with ws only.

[DiegoRBaquero]

Agreed, gonna close this.

On another topic @lpinca, why not unref all sockets? Googling didn't throw much.

[lpinca]

Because I think it's better to use unref only when really necessary.