Investigate flaky test-https-set-timeout-server on Raspberry Pi

[Trott]

• Version: v9.0.0-pre
• Platform: pi1-raspbian-wheezy
• Subsystem: test, https

https://ci.nodejs.org/job/node-test-binary-arm/9111/RUN_SUBSET=0,label=pi1-raspbian-wheezy/console

not ok 219 sequential/test-https-set-timeout-server
  ---
  duration_ms: 10.610
  severity: fail
  stack: |-
    Mismatched <anonymous> function calls. Expected exactly 1, actual 0.
        at Object.exports.mustCall (/home/iojs/build/workspace/node-test-binary-arm/test/common/index.js:484:10)
        at serverTimeout (/home/iojs/build/workspace/node-test-binary-arm/test/sequential/test-https-set-timeout-server.js:57:12)
        at /home/iojs/build/workspace/node-test-binary-arm/test/common/index.js:518:15
        at run (/home/iojs/build/workspace/node-test-binary-arm/test/sequential/test-https-set-timeout-server.js:50:5)
        at _combinedTickCallback (internal/process/next_tick.js:131:7)
        at process._tickCallback (internal/process/next_tick.js:180:9)
        at Function.Module.runMain (module.js:607:11)
        at startup (bootstrap_node.js:158:16)
        at bootstrap_node.js:575:3

@nodejs/testing @nodejs/http

[Trott]

Problem might be solved by moving cb() in all the test cases to inside a callback for server.close() rather than invoking it immediately after server.close() is invoked. Same might have to happen in corresponding http test.

[Trott]

(There could also be a case for moving each test into its own test file to rule out side effects.)

[Trott]

Moving the test to parallel and running it under load reproduces the issue.

$ tools/test.py -j92 --repeat 92 test/parallel/test-https-set-timeout-server.js  
=== release test-https-set-timeout-server ===                    
Path: parallel/test-https-set-timeout-server
Mismatched <anonymous> function calls. Expected exactly 1, actual 0.
    at Object.exports.mustCall (/Users/trott/io.js/test/common/index.js:484:10)
    at serverTimeout (/Users/trott/io.js/test/parallel/test-https-set-timeout-server.js:57:12)
    at /Users/trott/io.js/test/common/index.js:518:15
    at run (/Users/trott/io.js/test/parallel/test-https-set-timeout-server.js:50:5)
    at _combinedTickCallback (internal/process/next_tick.js:131:7)
    at process._tickCallback (internal/process/next_tick.js:180:9)
    at Function.Module.runMain (module.js:607:11)
    at startup (bootstrap_node.js:158:16)
    at bootstrap_node.js:575:3
...

[Trott]

If I comment out the first and last test case, the test becomes reliable.

[Trott]

@nodejs/http Is the following a bug or is it expected behavior?

Given this code:

const https = require('https');
const server = https.createServer(
  {key: keyfile, cert: certfile},
  function connectionListener(req, res) {
    // just do nothing, we should get a timeout event.
  });
server.listen(() => {
  const s = server.setTimeout(50, (socket) => {
    socket.destroy();
    server.close();
  });
  https.get({
    port: server.address().port,
    rejectUnauthorized: false
  }).on('error', () => {});
});

... connectionListener() may not run. Normally, it would. But it's not guaranteed as under load, the socket hangup/ECONNRESET may happen before the listener handler.

Bug? Expected behavior? Incorrect observation on my part? Something else?

[Trott]

On the assumption that the behavior described in the above comment is Not A Bug, I've opened #14134.