Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

test: flaky test-net-can-reset-timeout #14241

Closed
refack opened this issue Jul 14, 2017 · 4 comments
Closed

test: flaky test-net-can-reset-timeout #14241

refack opened this issue Jul 14, 2017 · 4 comments
Labels
flaky-test Issues and PRs related to the tests with unstable failures on the CI. freebsd Issues and PRs related to the FreeBSD platform. net Issues and PRs related to the net subsystem. stream Issues and PRs related to the stream subsystem. test Issues and PRs related to the tests.

Comments

@refack
Copy link
Contributor

refack commented Jul 14, 2017

  • Version: master
  • Platform: freeBSD
  • Subsystem: test,net,stream

https://ci.nodejs.org/job/node-test-commit-freebsd/10321/nodes=freebsd10-64/

not ok 820 parallel/test-net-can-reset-timeout
  ---
  duration_ms: 2.482
  severity: fail
  stack: |-
    timeout
    timeout
    server side end
    client side end
    Mismatched <anonymous> function calls. Expected exactly 1, actual 2.
        at Object.exports.mustCall (/usr/home/iojs/build/workspace/node-test-commit-freebsd/nodes/freebsd10-64/test/common/index.js:481:10)
        at Server.<anonymous> (/usr/home/iojs/build/workspace/node-test-commit-freebsd/nodes/freebsd10-64/test/parallel/test-net-can-reset-timeout.js:31:31)
        at Server.<anonymous> (/usr/home/iojs/build/workspace/node-test-commit-freebsd/nodes/freebsd10-64/test/common/index.js:513:15)
        at emitOne (events.js:115:13)
        at Server.emit (events.js:210:7)
        at TCP.onconnection (net.js:1553:8)
  ...

The test:

'use strict';
const common = require('../common');
const net = require('net');

const server = net.createServer(common.mustCall(function(stream) {
  stream.setTimeout(100);

  stream.resume();

  stream.on('timeout', common.mustCall(function() {
    console.log('timeout');
    // try to reset the timeout.
    stream.write('WHAT.');
  }));

  stream.on('end', function() {
    console.log('server side end');
    stream.end();
  });
}));

server.listen(0, function() {
  const c = net.createConnection(this.address().port);

  c.on('data', function() {
    c.end();
  });

  c.on('end', function() {
    console.log('client side end');
    server.close();
  });
});

/cc @nodejs/testing @nodejs/platform-freebsd @nodejs/streams

P.S. to whomever tackles this, could you add a comment explaining what this is testing a la doc/guides/writing-tests.md

@refack refack added flaky-test Issues and PRs related to the tests with unstable failures on the CI. freebsd Issues and PRs related to the FreeBSD platform. net Issues and PRs related to the net subsystem. stream Issues and PRs related to the stream subsystem. test Issues and PRs related to the tests. labels Jul 14, 2017
@Trott
Copy link
Member

Trott commented Jul 15, 2017

Unsurprisingly, this is an issue with parallelism and is not specific to FreeBSD. It is probably just showing up on FreeBSD because that is one of our more parallelized hosts for tests in CI. It's also likely surfaced due to the start-up performance hit of turning off V8 snapshots; even though this test doesn't use child_process, it's performance is likely impacted by more resources being required by other tests starting up and possibly starting sub-processes in parallel.

Here is partial output of a reproduction on macOS:

$ tools/test.py -j 92 --repeat 920 test/parallel/test-net-can-reset-timeout.js
=== release test-net-can-reset-timeout ===                    
Path: parallel/test-net-can-reset-timeout
timeout
timeout
server side end
client side end
Mismatched <anonymous> function calls. Expected exactly 1, actual 2.
    at Object.exports.mustCall (/Users/rtrott/io.js/test/common/index.js:480:10)
    at Server.<anonymous> (/Users/rtrott/io.js/test/parallel/test-net-can-reset-timeout.js:31:31)
    at Server.<anonymous> (/Users/rtrott/io.js/test/common/index.js:512:15)
    at emitOne (events.js:115:13)
    at Server.emit (events.js:210:7)
    at TCP.onconnection (net.js:1553:8)
Command: out/Release/node /Users/rtrott/io.js/test/parallel/test-net-can-reset-timeout.js
=== release test-net-can-reset-timeout ===                    
Path: parallel/test-net-can-reset-timeout
timeout
timeout
server side end
client side end
Mismatched <anonymous> function calls. Expected exactly 1, actual 2.
    at Object.exports.mustCall (/Users/rtrott/io.js/test/common/index.js:480:10)
    at Server.<anonymous> (/Users/rtrott/io.js/test/parallel/test-net-can-reset-timeout.js:31:31)
    at Server.<anonymous> (/Users/rtrott/io.js/test/common/index.js:512:15)
    at emitOne (events.js:115:13)
    at Server.emit (events.js:210:7)
    at TCP.onconnection (net.js:1553:8)
Command: out/Release/node /Users/rtrott/io.js/test/parallel/test-net-can-reset-timeout.js
=== release test-net-can-reset-timeout ===                    
Path: parallel/test-net-can-reset-timeout
timeout
timeout
server side end
client side end
Mismatched <anonymous> function calls. Expected exactly 1, actual 2.
    at Object.exports.mustCall (/Users/rtrott/io.js/test/common/index.js:480:10)
    at Server.<anonymous> (/Users/rtrott/io.js/test/parallel/test-net-can-reset-timeout.js:31:31)
    at Server.<anonymous> (/Users/rtrott/io.js/test/common/index.js:512:15)
    at emitOne (events.js:115:13)
    at Server.emit (events.js:210:7)
    at TCP.onconnection (net.js:1553:8)
Command: out/Release/node /Users/rtrott/io.js/test/parallel/test-net-can-reset-timeout.js
=== release test-net-can-reset-timeout ===                    
Path: parallel/test-net-can-reset-timeout
timeout
timeout
server side end
client side end
Mismatched <anonymous> function calls. Expected exactly 1, actual 2.
    at Object.exports.mustCall (/Users/rtrott/io.js/test/common/index.js:480:10)
    at Server.<anonymous> (/Users/rtrott/io.js/test/parallel/test-net-can-reset-timeout.js:31:31)
    at Server.<anonymous> (/Users/rtrott/io.js/test/common/index.js:512:15)
    at emitOne (events.js:115:13)
    at Server.emit (events.js:210:7)
    at TCP.onconnection (net.js:1553:8)
Command: out/Release/node /Users/rtrott/io.js/test/parallel/test-net-can-reset-timeout.js
=== release test-net-can-reset-timeout ===                    
Path: parallel/test-net-can-reset-timeout
timeout
timeout
server side end
client side end
Mismatched <anonymous> function calls. Expected exactly 1, actual 2.
    at Object.exports.mustCall (/Users/rtrott/io.js/test/common/index.js:480:10)
    at Server.<anonymous> (/Users/rtrott/io.js/test/parallel/test-net-can-reset-timeout.js:31:31)
    at Server.<anonymous> (/Users/rtrott/io.js/test/common/index.js:512:15)
    at emitOne (events.js:115:13)
    at Server.emit (events.js:210:7)
    at TCP.onconnection (net.js:1553:8)
Command: out/Release/node /Users/rtrott/io.js/test/parallel/test-net-can-reset-timeout.js
=== release test-net-can-reset-timeout ===                    
Path: parallel/test-net-can-reset-timeout
timeout
timeout
server side end
client side end
Mismatched <anonymous> function calls. Expected exactly 1, actual 2.
    at Object.exports.mustCall (/Users/rtrott/io.js/test/common/index.js:480:10)
    at Server.<anonymous> (/Users/rtrott/io.js/test/parallel/test-net-can-reset-timeout.js:31:31)
    at Server.<anonymous> (/Users/rtrott/io.js/test/common/index.js:512:15)
    at emitOne (events.js:115:13)
    at Server.emit (events.js:210:7)
    at TCP.onconnection (net.js:1553:8)
Command: out/Release/node /Users/rtrott/io.js/test/parallel/test-net-can-reset-timeout.js
=== release test-net-can-reset-timeout ===                    
Path: parallel/test-net-can-reset-timeout
timeout
timeout
server side end
client side end
Mismatched <anonymous> function calls. Expected exactly 1, actual 2.
    at Object.exports.mustCall (/Users/rtrott/io.js/test/common/index.js:480:10)
    at Server.<anonymous> (/Users/rtrott/io.js/test/parallel/test-net-can-reset-timeout.js:31:31)
    at Server.<anonymous> (/Users/rtrott/io.js/test/common/index.js:512:15)
    at emitOne (events.js:115:13)
    at Server.emit (events.js:210:7)
    at TCP.onconnection (net.js:1553:8)
Command: out/Release/node /Users/rtrott/io.js/test/parallel/test-net-can-reset-timeout.js

@Trott
Copy link
Member

Trott commented Jul 15, 2017

Problem occurs if the timeout fires more than once which can happen on a heavily loaded host. The test ought to permit timeout firing multiple times. It was written for nodejs/node-v0.x-archive#481.

@Trott
Copy link
Member

Trott commented Jul 15, 2017

Fix coming in a few minutes.

@Trott
Copy link
Member

Trott commented Jul 15, 2017

Fix is in #14257.

Trott added a commit to Trott/io.js that referenced this issue Jul 16, 2017
@Trott Trott closed this as completed in 5d3609d Jul 16, 2017
addaleax pushed a commit that referenced this issue Jul 18, 2017
Use `.once()` rather than `.on()` for timeout listener.

Add comment with URL for issue explaining the purpose of the test. (h/t
refack)

PR-URL: #14257
Fixes: #14241
Reviewed-By: Refael Ackermann <refack@gmail.com>
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Yuta Hiroto <hello@about-hiroppy.com>
Fishrock123 pushed a commit that referenced this issue Jul 19, 2017
Use `.once()` rather than `.on()` for timeout listener.

Add comment with URL for issue explaining the purpose of the test. (h/t
refack)

PR-URL: #14257
Fixes: #14241
Reviewed-By: Refael Ackermann <refack@gmail.com>
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Yuta Hiroto <hello@about-hiroppy.com>
MylesBorins pushed a commit that referenced this issue Aug 16, 2017
Use `.once()` rather than `.on()` for timeout listener.

Add comment with URL for issue explaining the purpose of the test. (h/t
refack)

PR-URL: #14257
Fixes: #14241
Reviewed-By: Refael Ackermann <refack@gmail.com>
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Yuta Hiroto <hello@about-hiroppy.com>
MylesBorins pushed a commit that referenced this issue Aug 16, 2017
Use `.once()` rather than `.on()` for timeout listener.

Add comment with URL for issue explaining the purpose of the test. (h/t
refack)

PR-URL: #14257
Fixes: #14241
Reviewed-By: Refael Ackermann <refack@gmail.com>
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Yuta Hiroto <hello@about-hiroppy.com>
MylesBorins pushed a commit that referenced this issue Sep 5, 2017
Use `.once()` rather than `.on()` for timeout listener.

Add comment with URL for issue explaining the purpose of the test. (h/t
refack)

PR-URL: #14257
Fixes: #14241
Reviewed-By: Refael Ackermann <refack@gmail.com>
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Yuta Hiroto <hello@about-hiroppy.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
flaky-test Issues and PRs related to the tests with unstable failures on the CI. freebsd Issues and PRs related to the FreeBSD platform. net Issues and PRs related to the net subsystem. stream Issues and PRs related to the stream subsystem. test Issues and PRs related to the tests.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants