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

timers: run nextTicks + MTQ between timers / immediates #22316

Closed
wants to merge 1 commit into from
Closed

timers: run nextTicks + MTQ between timers / immediates #22316

wants to merge 1 commit into from

Conversation

Fishrock123
Copy link
Contributor

Refs: #22257

This is semver-major because it changes significant timing guarentees. The tests do not pass because of the changes to Immediates.

Do not run the core tests, they will stall!

Checklist
  • make -j4 test (UNIX), or vcbuild test (Windows) passes
  • tests and/or benchmarks are included
  • documentation is changed or added
  • commit message follows commit guidelines

@Fishrock123 Fishrock123 added wip Issues and PRs that are still a work in progress. timers Issues and PRs related to the timers subsystem / setImmediate, setInterval, setTimeout. semver-major PRs that contain breaking changes and should be released in the next major version. labels Aug 14, 2018
@nodejs-github-bot
Copy link
Collaborator

@Fishrock123 build started: https://ci.nodejs.org/blue/organizations/jenkins/node-test-pull-request-lite-pipeline/detail/node-test-pull-request-lite-pipeline/559/pipeline

@nodejs-github-bot nodejs-github-bot added the timers Issues and PRs related to the timers subsystem / setImmediate, setInterval, setTimeout. label Aug 14, 2018
@Fishrock123
Copy link
Contributor Author

Ugh, how do I stop those?

@Fishrock123 Fishrock123 mentioned this pull request Aug 14, 2018
Closed
@Fishrock123
Copy link
Contributor Author

Fishrock123 commented Aug 14, 2018 •
edited
Loading

CITGM (I think I did this right): https://ci.nodejs.org/view/Node.js-citgm/job/citgm-smoker/1506/

@devsnek
Copy link
Member

devsnek commented Aug 14, 2018

@Fishrock123 I cancelled the Travis CI

@apapirovski
Copy link
Member

apapirovski commented Aug 14, 2018 •
edited
Loading

So, I think this might need to be slightly more complicated to account for proper error handling but I'll need to confirm (if next tick queue throws). Will review and test in more detail before tomorrow morning.

@Fishrock123
Copy link
Contributor Author

Hmm, CITGM builds seem to have failed? @nodejs/build

@Fishrock123
Copy link
Contributor Author

Ok well, this patch allows the tests to run but also causes many async_hooks segfaults:

diff --git a/lib/timers.js b/lib/timers.js
index 6e473456b9..090ae60ff4 100644
--- a/lib/timers.js
+++ b/lib/timers.js
@@ -613,7 +613,11 @@ function processImmediate() {
 
     emitAfter(asyncId);
 
-    runNextTicks();
+    try {
+      runNextTicks();
+    } catch (e) {
+
+    }
 
     immediate = immediate._idleNext;
   }
[04:53|% 100|+ 2356|- 9]: Done 
=== release test-common ===
Path: parallel/test-common
foo
bar
baz
test
foo
bar
baz
test
Error: async hook stack has become corrupted (actual: 22, expected: 0)
 1: 0x100005432 node::Environment::AsyncHooks::pop_async_id(double) [/Users/Jeremiah/Documents/node/out/Release/node]
 2: 0x10000f9cf node::InternalCallbackScope::Close() [/Users/Jeremiah/Documents/node/out/Release/node]
 3: 0x100035d37 node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/Jeremiah/Documents/node/out/Release/node]
 4: 0x100035f56 node::MakeCallback(v8::Isolate*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/Jeremiah/Documents/node/out/Release/node]
 5: 0x100023080 node::Environment::CheckImmediate(uv_check_s*) [/Users/Jeremiah/Documents/node/out/Release/node]
 6: 0x10098e9dc uv__run_check [/Users/Jeremiah/Documents/node/out/Release/node]
 7: 0x100989f79 uv_run [/Users/Jeremiah/Documents/node/out/Release/node]
 8: 0x10003e166 node::Start(v8::Isolate*, node::IsolateData*, int, char const* const*, int, char const* const*) [/Users/Jeremiah/Documents/node/out/Release/node]
 9: 0x10003d51e node::Start(uv_loop_s*, int, char const* const*, int, char const* const*) [/Users/Jeremiah/Documents/node/out/Release/node]
10: 0x10003d1cb node::Start(int, char**) [/Users/Jeremiah/Documents/node/out/Release/node]
11: 0x100001034 start [/Users/Jeremiah/Documents/node/out/Release/node]
12: 0x2
Command: out/Release/node /Users/Jeremiah/Documents/node/test/parallel/test-common.js
=== release test-domain-error-types ===
Path: parallel/test-domain-error-types
Error: async hook stack has become corrupted (actual: 3, expected: 0)
 1: 0x100005432 node::Environment::AsyncHooks::pop_async_id(double) [/Users/Jeremiah/Documents/node/out/Release/node]
 2: 0x10000f9cf node::InternalCallbackScope::Close() [/Users/Jeremiah/Documents/node/out/Release/node]
 3: 0x100035d37 node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/Jeremiah/Documents/node/out/Release/node]
 4: 0x100035f56 node::MakeCallback(v8::Isolate*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/Jeremiah/Documents/node/out/Release/node]
 5: 0x100023080 node::Environment::CheckImmediate(uv_check_s*) [/Users/Jeremiah/Documents/node/out/Release/node]
 6: 0x10098e9dc uv__run_check [/Users/Jeremiah/Documents/node/out/Release/node]
 7: 0x100989f79 uv_run [/Users/Jeremiah/Documents/node/out/Release/node]
 8: 0x10003e166 node::Start(v8::Isolate*, node::IsolateData*, int, char const* const*, int, char const* const*) [/Users/Jeremiah/Documents/node/out/Release/node]
 9: 0x10003d51e node::Start(uv_loop_s*, int, char const* const*, int, char const* const*) [/Users/Jeremiah/Documents/node/out/Release/node]
10: 0x10003d1cb node::Start(int, char**) [/Users/Jeremiah/Documents/node/out/Release/node]
11: 0x100001034 start [/Users/Jeremiah/Documents/node/out/Release/node]
12: 0x2
Command: out/Release/node /Users/Jeremiah/Documents/node/test/parallel/test-domain-error-types.js
=== release test-domain-multiple-errors ===
Path: parallel/test-domain-multiple-errors
Error: async hook stack has become corrupted (actual: 3, expected: 0)
 1: 0x100005432 node::Environment::AsyncHooks::pop_async_id(double) [/Users/Jeremiah/Documents/node/out/Release/node]
 2: 0x10000f9cf node::InternalCallbackScope::Close() [/Users/Jeremiah/Documents/node/out/Release/node]
 3: 0x100035d37 node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/Jeremiah/Documents/node/out/Release/node]
 4: 0x100035f56 node::MakeCallback(v8::Isolate*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/Jeremiah/Documents/node/out/Release/node]
 5: 0x100023080 node::Environment::CheckImmediate(uv_check_s*) [/Users/Jeremiah/Documents/node/out/Release/node]
 6: 0x10098e9dc uv__run_check [/Users/Jeremiah/Documents/node/out/Release/node]
 7: 0x100989f79 uv_run [/Users/Jeremiah/Documents/node/out/Release/node]
 8: 0x10003e166 node::Start(v8::Isolate*, node::IsolateData*, int, char const* const*, int, char const* const*) [/Users/Jeremiah/Documents/node/out/Release/node]
 9: 0x10003d51e node::Start(uv_loop_s*, int, char const* const*, int, char const* const*) [/Users/Jeremiah/Documents/node/out/Release/node]
10: 0x10003d1cb node::Start(int, char**) [/Users/Jeremiah/Documents/node/out/Release/node]
11: 0x100001034 start [/Users/Jeremiah/Documents/node/out/Release/node]
12: 0x2
Command: out/Release/node /Users/Jeremiah/Documents/node/test/parallel/test-domain-multiple-errors.js
=== release test-domain-stack ===
Path: parallel/test-domain-stack
Error: async hook stack has become corrupted (actual: 3, expected: 0)
 1: 0x100005432 node::Environment::AsyncHooks::pop_async_id(double) [/Users/Jeremiah/Documents/node/out/Release/node]
 2: 0x10000f9cf node::InternalCallbackScope::Close() [/Users/Jeremiah/Documents/node/out/Release/node]
 3: 0x100035d37 node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/Jeremiah/Documents/node/out/Release/node]
 4: 0x100035f56 node::MakeCallback(v8::Isolate*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/Jeremiah/Documents/node/out/Release/node]
 5: 0x100023080 node::Environment::CheckImmediate(uv_check_s*) [/Users/Jeremiah/Documents/node/out/Release/node]
 6: 0x10098e9dc uv__run_check [/Users/Jeremiah/Documents/node/out/Release/node]
 7: 0x100989f79 uv_run [/Users/Jeremiah/Documents/node/out/Release/node]
 8: 0x10003e166 node::Start(v8::Isolate*, node::IsolateData*, int, char const* const*, int, char const* const*) [/Users/Jeremiah/Documents/node/out/Release/node]
 9: 0x10003d51e node::Start(uv_loop_s*, int, char const* const*, int, char const* const*) [/Users/Jeremiah/Documents/node/out/Release/node]
10: 0x10003d1cb node::Start(int, char**) [/Users/Jeremiah/Documents/node/out/Release/node]
11: 0x100001034 start [/Users/Jeremiah/Documents/node/out/Release/node]
Command: out/Release/node /Users/Jeremiah/Documents/node/test/parallel/test-domain-stack.js
=== release test-process-fatal-exception-tick ===
Path: parallel/test-process-fatal-exception-tick
Error: async hook stack has become corrupted (actual: 6, expected: 0)
 1: 0x100005432 node::Environment::AsyncHooks::pop_async_id(double) [/Users/Jeremiah/Documents/node/out/Release/node]
 2: 0x10000f9cf node::InternalCallbackScope::Close() [/Users/Jeremiah/Documents/node/out/Release/node]
 3: 0x100035d37 node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/Jeremiah/Documents/node/out/Release/node]
 4: 0x100035f56 node::MakeCallback(v8::Isolate*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/Jeremiah/Documents/node/out/Release/node]
 5: 0x100023080 node::Environment::CheckImmediate(uv_check_s*) [/Users/Jeremiah/Documents/node/out/Release/node]
 6: 0x10098e9dc uv__run_check [/Users/Jeremiah/Documents/node/out/Release/node]
 7: 0x100989f79 uv_run [/Users/Jeremiah/Documents/node/out/Release/node]
 8: 0x10003e166 node::Start(v8::Isolate*, node::IsolateData*, int, char const* const*, int, char const* const*) [/Users/Jeremiah/Documents/node/out/Release/node]
 9: 0x10003d51e node::Start(uv_loop_s*, int, char const* const*, int, char const* const*) [/Users/Jeremiah/Documents/node/out/Release/node]
10: 0x10003d1cb node::Start(int, char**) [/Users/Jeremiah/Documents/node/out/Release/node]
11: 0x100001034 start [/Users/Jeremiah/Documents/node/out/Release/node]
Command: out/Release/node /Users/Jeremiah/Documents/node/test/parallel/test-process-fatal-exception-tick.js
=== release test-process-next-tick ===
Path: parallel/test-process-next-tick
Error: async hook stack has become corrupted (actual: 3, expected: 0)
 1: 0x100005432 node::Environment::AsyncHooks::pop_async_id(double) [/Users/Jeremiah/Documents/node/out/Release/node]
 2: 0x10000f9cf node::InternalCallbackScope::Close() [/Users/Jeremiah/Documents/node/out/Release/node]
 3: 0x100035d37 node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/Jeremiah/Documents/node/out/Release/node]
 4: 0x100035f56 node::MakeCallback(v8::Isolate*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/Jeremiah/Documents/node/out/Release/node]
 5: 0x100023080 node::Environment::CheckImmediate(uv_check_s*) [/Users/Jeremiah/Documents/node/out/Release/node]
 6: 0x10098e9dc uv__run_check [/Users/Jeremiah/Documents/node/out/Release/node]
 7: 0x100989f79 uv_run [/Users/Jeremiah/Documents/node/out/Release/node]
 8: 0x10003e166 node::Start(v8::Isolate*, node::IsolateData*, int, char const* const*, int, char const* const*) [/Users/Jeremiah/Documents/node/out/Release/node]
 9: 0x10003d51e node::Start(uv_loop_s*, int, char const* const*, int, char const* const*) [/Users/Jeremiah/Documents/node/out/Release/node]
10: 0x10003d1cb node::Start(int, char**) [/Users/Jeremiah/Documents/node/out/Release/node]
11: 0x100001034 start [/Users/Jeremiah/Documents/node/out/Release/node]
12: 0x2
Command: out/Release/node /Users/Jeremiah/Documents/node/test/parallel/test-process-next-tick.js
=== release test-timers-immediate-queue ===                                   t
Path: parallel/test-timers-immediate-queue
hit 1
assert.js:84
  throw new AssertionError(obj);
  ^

AssertionError [ERR_ASSERTION]: Expected inputs to be strictly equal:

1 !== 1000

    at process.<anonymous> (/Users/Jeremiah/Documents/node/test/parallel/test-timers-immediate-queue.js:53:10)
    at process.emit (events.js:187:15)
Command: out/Release/node /Users/Jeremiah/Documents/node/test/parallel/test-timers-immediate-queue.js
=== release test ===
Path: addons/make-callback-recurse/test
Error: async hook stack has become corrupted (actual: 15, expected: 0)
 1: 0x100005432 node::Environment::AsyncHooks::pop_async_id(double) [/Users/Jeremiah/Documents/node/out/Release/node]
 2: 0x10000f9cf node::InternalCallbackScope::Close() [/Users/Jeremiah/Documents/node/out/Release/node]
 3: 0x100035d37 node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/Jeremiah/Documents/node/out/Release/node]
 4: 0x100035f56 node::MakeCallback(v8::Isolate*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/Jeremiah/Documents/node/out/Release/node]
 5: 0x100023080 node::Environment::CheckImmediate(uv_check_s*) [/Users/Jeremiah/Documents/node/out/Release/node]
 6: 0x10098e9dc uv__run_check [/Users/Jeremiah/Documents/node/out/Release/node]
 7: 0x100989f79 uv_run [/Users/Jeremiah/Documents/node/out/Release/node]
 8: 0x10003e166 node::Start(v8::Isolate*, node::IsolateData*, int, char const* const*, int, char const* const*) [/Users/Jeremiah/Documents/node/out/Release/node]
 9: 0x10003d51e node::Start(uv_loop_s*, int, char const* const*, int, char const* const*) [/Users/Jeremiah/Documents/node/out/Release/node]
10: 0x10003d1cb node::Start(int, char**) [/Users/Jeremiah/Documents/node/out/Release/node]
11: 0x100001034 start [/Users/Jeremiah/Documents/node/out/Release/node]
12: 0x2
Command: out/Release/node /Users/Jeremiah/Documents/node/test/addons/make-callback-recurse/test.js
=== release test ===
Path: addons-napi/test_make_callback_recurse/test
Error: async hook stack has become corrupted (actual: 15, expected: 0)
 1: 0x100005432 node::Environment::AsyncHooks::pop_async_id(double) [/Users/Jeremiah/Documents/node/out/Release/node]
 2: 0x10000f9cf node::InternalCallbackScope::Close() [/Users/Jeremiah/Documents/node/out/Release/node]
 3: 0x100035d37 node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/Jeremiah/Documents/node/out/Release/node]
 4: 0x100035f56 node::MakeCallback(v8::Isolate*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/Jeremiah/Documents/node/out/Release/node]
 5: 0x100023080 node::Environment::CheckImmediate(uv_check_s*) [/Users/Jeremiah/Documents/node/out/Release/node]
 6: 0x10098e9dc uv__run_check [/Users/Jeremiah/Documents/node/out/Release/node]
 7: 0x100989f79 uv_run [/Users/Jeremiah/Documents/node/out/Release/node]
 8: 0x10003e166 node::Start(v8::Isolate*, node::IsolateData*, int, char const* const*, int, char const* const*) [/Users/Jeremiah/Documents/node/out/Release/node]
 9: 0x10003d51e node::Start(uv_loop_s*, int, char const* const*, int, char const* const*) [/Users/Jeremiah/Documents/node/out/Release/node]
10: 0x10003d1cb node::Start(int, char**) [/Users/Jeremiah/Documents/node/out/Release/node]
11: 0x100001034 start [/Users/Jeremiah/Documents/node/out/Release/node]
Command: out/Release/node /Users/Jeremiah/Documents/node/test/addons-napi/test_make_callback_recurse/test.js
[04:53|% 100|+ 2356|-   9]: Done
make[1]: *** [jstest] Error 1
make: *** [test] Error 2

@maclover7
Copy link
Contributor

Hmm, CITGM builds seem to have failed?

@Fishrock123 This happens on architectures which are only supported by some versions of Node.js, but not the one that the CITGM job is testing (ex: Ubuntu 12.04). This is being tracked at nodejs/build#1430

@apapirovski apapirovski mentioned this pull request Sep 13, 2018
Closed
3 tasks
@Fishrock123
Copy link
Contributor Author

Superseded by #22842

@Fishrock123 Fishrock123 closed this Nov 6, 2018
@Fishrock123 Fishrock123 deleted the timers-immediates-run-nextticks branch November 6, 2018 18:46
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@apapirovski apapirovski Awaiting requested review from apapirovski

Assignees
No one assigned
Labels
semver-major PRs that contain breaking changes and should be released in the next major version. timers Issues and PRs related to the timers subsystem / setImmediate, setInterval, setTimeout. wip Issues and PRs that are still a work in progress.
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
5 participants
@Fishrock123 @nodejs-github-bot @devsnek @apapirovski @maclover7