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.

Sign up for GitHub

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

Jump to bottom

Investigate flaky sequential/test-timers-same-timeout-wrong-list-deleted #8459

Closed
Trott opened this issue Sep 9, 2016 · 6 comments
Closed

Investigate flaky sequential/test-timers-same-timeout-wrong-list-deleted #8459

Trott opened this issue Sep 9, 2016 · 6 comments
Labels
test Issues and PRs related to the tests. timers Issues and PRs related to the timers subsystem / setImmediate, setInterval, setTimeout.

Comments

@Trott
Copy link
Member

Trott commented Sep 9, 2016

Sample failure: https://ci.nodejs.org/job/node-test-binary-windows/3706/RUN_SUBSET=3,VS_VERSION=vcbt2015,label=win10/console

not ok 238 parallel/test-timers-same-timeout-wrong-list-deleted
# 
# assert.js:85
#   throw new assert.AssertionError({
#   ^
# AssertionError: Elapsed time does not include second timer's timeout.
#     at process.<anonymous> (c:\workspace\node-test-binary-windows\RUN_SUBSET\3\VS_VERSION\vcbt2015\label\win10\test\parallel\test-timers-same-timeout-wrong-list-deleted.js:26:10)
#     at emitOne (events.js:101:20)
#     at process.emit (events.js:188:7)
  ---
  duration_ms: 1.128
@Trott Trott added windows Issues and PRs related to the Windows platform. test Issues and PRs related to the tests. timers Issues and PRs related to the timers subsystem / setImmediate, setInterval, setTimeout. labels Sep 9, 2016
@Trott
Copy link
Member Author

Trott commented Sep 9, 2016

Might help #8422 if this gets fixed.

@nodejs/testing @Fishrock123 @nodejs/platform-windows

@Fishrock123
Copy link
Contributor

This sounds like an ages old problem where timers on windows fired early, but I thought that got fixed?

cc @misterdjules & @saghul

@saghul
Copy link
Member

saghul commented Sep 12, 2016

AFAIK that got fixed :-S

@misterdjules misterdjules mentioned this issue Oct 15, 2016
Merged
@mscdex
Copy link
Contributor

mscdex commented Dec 20, 2016

I just saw this happen on CI on an ubuntu1610-x64 node on the master branch.

not ok 1310 sequential/test-timers-same-timeout-wrong-list-deleted
  ---
  duration_ms: 0.844
  severity: fail
  stack: |-
    
    assert.js:85
      throw new assert.AssertionError({
      ^
    AssertionError: Elapsed time does not include second timer's timeout.
        at process.<anonymous> (/home/iojs/build/workspace/node-test-commit-linux/nodes/ubuntu1610-x64/test/sequential/test-timers-same-timeout-wrong-list-deleted.js:26:10)
        at emitOne (events.js:101:20)
        at process.emit (events.js:188:7)

@mscdex mscdex removed the windows Issues and PRs related to the Windows platform. label Dec 20, 2016
@Trott Trott changed the title Investigate flaky parallel/test-timers-same-timeout-wrong-list-deleted on Windows Investigate flaky parallel/test-timers-same-timeout-wrong-list-deleted Dec 20, 2016
@Trott Trott changed the title Investigate flaky parallel/test-timers-same-timeout-wrong-list-deleted Investigate flaky sequential/test-timers-same-timeout-wrong-list-deleted Dec 20, 2016
@Trott
Copy link
Member Author

Trott commented Dec 20, 2016

Looking at the test, it is inherently flaky and will fail on a machine under load on any operating system. I've removed "Windows" from the title of this issue.

Moving it to sequential probably has helped, but best to fix the test entirely. I'll try to take a look at it later, but if anyone wants to beat me to it, feel free.

@Trott
Copy link
Member Author

Trott commented Dec 20, 2016

Fixed in #10362

Trott added a commit to Trott/io.js that referenced this issue Dec 20, 2016
@Trott
test: fix timers-same-timeout-wrong-list-deleted
16c7a54 
test-timers-same-timeout-wrong-list-deleted was flaky under load because
there is no guarantee that a timer will fire within a given period of
time. It had an exit handler that checked that the process was finishing
in less than twice as much as a timer was set for. Under load, the
timer could take over 200ms to fire even if it was set for 100ms, so
this was causing the test to be flaky on CI from time to time.

However, that timing check is unnecessary to identify the regression
that the test was written for. When run with a version of Node.js that
does not contain the fix that accompanied the test in its initial
commit, an assertion indicating that there were still timers in the
active timer list fired. So, this commit removes the exit handler timing
check and relies on the existing robust active timers list length check.

This allows us to move the test back to parallel because it does not
seem to fail under load anymore.

The test was refactored slightly, removing duplicated code to a
function, using `assert.strictEqual()` instead of `assert.equal()`,
changing a 10ms timer to 1ms, and improving the messages provided by
assertions.

Fixes: nodejs#8459
@Trott Trott closed this as completed in 4bdf494 Dec 23, 2016
evanlucas pushed a commit that referenced this issue Jan 3, 2017
@Trott @evanlucas
test: fix timers-same-timeout-wrong-list-deleted
83a991b 
test-timers-same-timeout-wrong-list-deleted was flaky under load because
there is no guarantee that a timer will fire within a given period of
time. It had an exit handler that checked that the process was finishing
in less than twice as much as a timer was set for. Under load, the
timer could take over 200ms to fire even if it was set for 100ms, so
this was causing the test to be flaky on CI from time to time.

However, that timing check is unnecessary to identify the regression
that the test was written for. When run with a version of Node.js that
does not contain the fix that accompanied the test in its initial
commit, an assertion indicating that there were still timers in the
active timer list fired. So, this commit removes the exit handler timing
check and relies on the existing robust active timers list length check.

This allows us to move the test back to parallel because it does not
seem to fail under load anymore.

The test was refactored slightly, removing duplicated code to a
function, using `assert.strictEqual()` instead of `assert.equal()`,
changing a 10ms timer to 1ms, and improving the messages provided by
assertions.

Fixes: #8459
PR-URL: #10362
Reviewed-By: Jeremiah Senkpiel <fishrock123@rocketmail.com>
Reviewed-By: James M Snell <jasnell@gmail.com>
evanlucas pushed a commit that referenced this issue Jan 4, 2017
@Trott @evanlucas
test: fix timers-same-timeout-wrong-list-deleted
501165f 
test-timers-same-timeout-wrong-list-deleted was flaky under load because
there is no guarantee that a timer will fire within a given period of
time. It had an exit handler that checked that the process was finishing
in less than twice as much as a timer was set for. Under load, the
timer could take over 200ms to fire even if it was set for 100ms, so
this was causing the test to be flaky on CI from time to time.

However, that timing check is unnecessary to identify the regression
that the test was written for. When run with a version of Node.js that
does not contain the fix that accompanied the test in its initial
commit, an assertion indicating that there were still timers in the
active timer list fired. So, this commit removes the exit handler timing
check and relies on the existing robust active timers list length check.

This allows us to move the test back to parallel because it does not
seem to fail under load anymore.

The test was refactored slightly, removing duplicated code to a
function, using `assert.strictEqual()` instead of `assert.equal()`,
changing a 10ms timer to 1ms, and improving the messages provided by
assertions.

Fixes: #8459
PR-URL: #10362
Reviewed-By: Jeremiah Senkpiel <fishrock123@rocketmail.com>
Reviewed-By: James M Snell <jasnell@gmail.com>
MylesBorins pushed a commit that referenced this issue Jan 23, 2017
@Trott @MylesBorins
test: fix timers-same-timeout-wrong-list-deleted
885fb67 
test-timers-same-timeout-wrong-list-deleted was flaky under load because
there is no guarantee that a timer will fire within a given period of
time. It had an exit handler that checked that the process was finishing
in less than twice as much as a timer was set for. Under load, the
timer could take over 200ms to fire even if it was set for 100ms, so
this was causing the test to be flaky on CI from time to time.

However, that timing check is unnecessary to identify the regression
that the test was written for. When run with a version of Node.js that
does not contain the fix that accompanied the test in its initial
commit, an assertion indicating that there were still timers in the
active timer list fired. So, this commit removes the exit handler timing
check and relies on the existing robust active timers list length check.

This allows us to move the test back to parallel because it does not
seem to fail under load anymore.

The test was refactored slightly, removing duplicated code to a
function, using `assert.strictEqual()` instead of `assert.equal()`,
changing a 10ms timer to 1ms, and improving the messages provided by
assertions.

Fixes: #8459
PR-URL: #10362
Reviewed-By: Jeremiah Senkpiel <fishrock123@rocketmail.com>
Reviewed-By: James M Snell <jasnell@gmail.com>
MylesBorins pushed a commit that referenced this issue Jan 24, 2017
@Trott @MylesBorins
test: fix timers-same-timeout-wrong-list-deleted
efbed9c 
test-timers-same-timeout-wrong-list-deleted was flaky under load because
there is no guarantee that a timer will fire within a given period of
time. It had an exit handler that checked that the process was finishing
in less than twice as much as a timer was set for. Under load, the
timer could take over 200ms to fire even if it was set for 100ms, so
this was causing the test to be flaky on CI from time to time.

However, that timing check is unnecessary to identify the regression
that the test was written for. When run with a version of Node.js that
does not contain the fix that accompanied the test in its initial
commit, an assertion indicating that there were still timers in the
active timer list fired. So, this commit removes the exit handler timing
check and relies on the existing robust active timers list length check.

This allows us to move the test back to parallel because it does not
seem to fail under load anymore.

The test was refactored slightly, removing duplicated code to a
function, using `assert.strictEqual()` instead of `assert.equal()`,
changing a 10ms timer to 1ms, and improving the messages provided by
assertions.

Fixes: #8459
PR-URL: #10362
Reviewed-By: Jeremiah Senkpiel <fishrock123@rocketmail.com>
Reviewed-By: James M Snell <jasnell@gmail.com>
MylesBorins pushed a commit that referenced this issue Jan 31, 2017
@Trott @MylesBorins
test: fix timers-same-timeout-wrong-list-deleted
8b44fb3 
test-timers-same-timeout-wrong-list-deleted was flaky under load because
there is no guarantee that a timer will fire within a given period of
time. It had an exit handler that checked that the process was finishing
in less than twice as much as a timer was set for. Under load, the
timer could take over 200ms to fire even if it was set for 100ms, so
this was causing the test to be flaky on CI from time to time.

However, that timing check is unnecessary to identify the regression
that the test was written for. When run with a version of Node.js that
does not contain the fix that accompanied the test in its initial
commit, an assertion indicating that there were still timers in the
active timer list fired. So, this commit removes the exit handler timing
check and relies on the existing robust active timers list length check.

This allows us to move the test back to parallel because it does not
seem to fail under load anymore.

The test was refactored slightly, removing duplicated code to a
function, using `assert.strictEqual()` instead of `assert.equal()`,
changing a 10ms timer to 1ms, and improving the messages provided by
assertions.

Fixes: #8459
PR-URL: #10362
Reviewed-By: Jeremiah Senkpiel <fishrock123@rocketmail.com>
Reviewed-By: James M Snell <jasnell@gmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
test Issues and PRs related to the tests. timers Issues and PRs related to the timers subsystem / setImmediate, setInterval, setTimeout.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@mscdex @saghul @Trott @Fishrock123