node,timers: fix beforeExit with unrefed timers #2795

Fishrock123 · 2015-09-10T12:18:06Z

Attempts to fix #1264.

My first actual c++ ever, done from an airport and low on time so I'm sure it'l need cleanup, especially about the _unrefed bit.

cc @trevnorris, @bnoordhuis

Fishrock123 · 2015-09-10T12:18:33Z

CI: https://ci.nodejs.org/job/node-test-pull-request/270/

ChALkeR · 2015-09-10T12:21:57Z

src/node.cc

@@ -1500,7 +1500,7 @@ void GetActiveHandles(const FunctionCallbackInfo<Value>& args) {
  Local<String> owner_sym = env->owner_string();

  for (auto w : *env->handle_wrap_queue()) {
-    if (w->persistent().IsEmpty() || (w->flags_ & HandleWrap::kUnref))
+    if (w->persistent().IsEmpty() /*|| (w->flags_ & HandleWrap::kUnref)*/)


Is there a reason to leave this commented out? Git keeps track of things.
If this is still wanted and something is not finished, a TODO might be reasonable here.

Oops haha. About to board my plane, couldn't fix everything up yet. :P

Fishrock123 · 2015-09-10T12:24:33Z

Note: should work (should) but may not be complete/polished. ;)

~~And I need to add an actual test :P~~

Fishrock123 · 2015-09-10T12:56:46Z

New CI with test: https://ci.nodejs.org/job/node-test-pull-request/271/

Fishrock123 · 2015-10-07T22:32:05Z

CI https://ci.nodejs.org/job/node-test-pull-request/447/

@trevnorris PTAL

trevnorris · 2015-10-08T18:46:06Z

src/node.cc

@@ -1543,6 +1543,18 @@ void GetActiveHandles(const FunctionCallbackInfo<Value>& args) {
  args.GetReturnValue().Set(ary);
 }

+bool HasUnrefedTimerHandles(Environment* env) {
+


nit: remove empty line.

trevnorris · 2015-10-08T19:11:37Z

few nits, but otherwise LGTM.

Fishrock123 · 2015-10-09T02:43:41Z

src/node.cc

@@ -3969,6 +3981,11 @@ static void StartNodeInstance(void* arg) {
          v8::platform::PumpMessageLoop(default_platform, isolate);
          EmitBeforeExit(env);

+          // We need to run an extra event loop turn to purge unrefed handles.
+          bool unrefedTimers = HasUnrefedTimerHandles(env);
+          if (unrefedTimers == true)


@trevnorris would it better for me to inline the HasUnrefedTimerHandles(env)?

naw. looks good as it is.

Fishrock123 · 2015-10-09T03:28:39Z

CI re-run: https://ci.nodejs.org/job/node-test-pull-request/462/

trevnorris · 2015-10-09T16:58:32Z

Only test-stringbytes-external.js is failing. LGTM.

thefourtheye · 2015-10-09T17:46:19Z

test/parallel/test-timers-unrefed-in-beforeexit.js

+
+var once = 0;
+
+process.on('beforeExit', () => {


Use common.mustCall(..., 1), you don't need the once variable at all.

trevnorris · 2015-10-09T20:08:05Z

@Fishrock123 Not including the new test, here's the current working change:

diff --git a/src/node.cc b/src/node.cc
index e5a87e7..068b548 100644
--- a/src/node.cc
+++ b/src/node.cc
@@ -3966,2 +3966,3 @@ static void StartNodeInstance(void* arg) {
       SealHandleScope seal(isolate);
+      uv_loop_t* const loop = env->event_loop();
       bool more;
@@ -3975,2 +3976,7 @@ static void StartNodeInstance(void* arg) {

+          // We need to run an extra event loop turn to purge unrefed handles.
+          if (loop->active_handles == 0 &&
+              loop->handle_queue[0] != loop->handle_queue[1])
+            uv_run(env->event_loop(), UV_RUN_NOWAIT);
+
           // Emit `beforeExit` if the loop became alive either after emitting
diff --git a/test/parallel/test-beforeexit-event.js b/test/parallel/test-beforeexit-event.js
index f3bd127..7519a87 100644
--- a/test/parallel/test-beforeexit-event.js
+++ b/test/parallel/test-beforeexit-event.js
@@ -32,3 +32,3 @@ function tryListen() {
   net.createServer()
-    .listen(common.PORT)
+    .listen(common.PORT, 'localhost')
     .on('listening', function() {

The change to test-beforeexit-event.js is because simply listening to common.PORT causes the listening callback to be called in a nextTick(). Meaning the server handle will be closed before the test has a chance to check whether it's active. I don't know how this test was passing up until now.

Fishrock123 · 2015-10-09T20:58:00Z

The change to test-beforeexit-event.js is because simply listening to common.PORT causes the listening callback to be called in a nextTick(). Meaning the server handle will be closed before the test has a chance to check whether it's active. I don't know how this test was passing up until now.

@trevnorris I can't repo the failure on master... is the test not erroring correctly?

trevnorris · 2015-10-09T21:36:00Z

@Fishrock123 Sorry. I mean that the test is broken, and shouldn't be working on master. Not that it doesn't.

Trying to use a net server here is not reasonable, instead try with a file.

Fishrock123 · 2015-10-09T23:04:36Z

Fixed. CI: https://ci.nodejs.org/job/node-test-pull-request/472/

Fishrock123 · 2015-10-10T17:26:18Z

Hmmm, windows is now failing my test.

not ok 723 test-timers-unrefed-in-beforeexit.js
# c:\workspace\node-test-commit-windows\nodes\win2012r2\test\parallel\test-timers-unrefed-in-beforeexit.js:10
# throw new RangeError('beforeExit should only have been called once!');
# ^
# 
# RangeError: beforeExit should only have been called once!
# at process.<anonymous> (c:\workspace\node-test-commit-windows\nodes\win2012r2\test\parallel\test-timers-unrefed-in-beforeexit.js:10:11)
# at emitOne (events.js:77:13)
# at process.emit (events.js:169:7)

trevnorris · 2015-10-10T18:06:32Z

@Fishrock123 it's possible we're depending on implementation details of libuv for that check that Windows doesn't follow. I can debug on Monday.

indutny · 2015-10-14T02:08:03Z

It looks like uv_close(timer) calls uv_ref() on it (in some sense).

If you will replace

node/lib/timers.js

Line 130 in e3d9d25

list.close();

with list.unref() (Yeah, it will leak memory. We do it just for testing purposes) - the test will pass. Looking deeper into it.

indutny · 2015-10-14T02:12:19Z

Yeah, confirmed. uv_close() refs the timer on windows, and does not on unix. cc @saghul : is there any reason why it is done this way? Should we attempt to make it consistent?

Fishrock123 · 2015-10-14T21:07:07Z

@indutny Saul is gone until the end of November I think. Could you maybe bring it up in git blame to see some context?

trevnorris · 2015-10-14T23:23:12Z

@indutny Here's a small patch:

diff --git a/deps/uv/src/win/handle.c b/deps/uv/src/win/handle.c
index 72b49d9..ab83f37 100644
--- a/deps/uv/src/win/handle.c
+++ b/deps/uv/src/win/handle.c
@@ -63,6 +63,7 @@ int uv_is_active(const uv_handle_t* handle) {
         !(handle->flags & UV__HANDLE_CLOSING);
 }

+#include <stdio.h>

 void uv_close(uv_handle_t* handle, uv_close_cb cb) {
   uv_loop_t* loop = handle->loop;
@@ -97,6 +98,7 @@ void uv_close(uv_handle_t* handle, uv_close_cb cb) {
       return;

     case UV_TIMER:
+      fprintf(stderr, "close on UV_TIMER\n");
       uv_timer_stop((uv_timer_t*)handle);
       uv__handle_closing(handle);
       uv_want_endgame(loop, handle);
diff --git a/deps/uv/src/win/timer.c b/deps/uv/src/win/timer.c
index 0da541a..d9d277a 100644
--- a/deps/uv/src/win/timer.c
+++ b/deps/uv/src/win/timer.c
@@ -117,10 +117,12 @@ int uv_timer_start(uv_timer_t* handle, uv_timer_cb timer_cb, uint64_t timeout,
   return 0;
 }

+#include <stdio.h>

 int uv_timer_stop(uv_timer_t* handle) {
   uv_loop_t* loop = handle->loop;

+  fprintf(stderr, "is active: %s\n", uv__is_active(handle) ? "true" : "false");
   if (!uv__is_active(handle))
     return 0;

And what I got from it was:

close on UV_TIMER
is active: true
is active: true

close on UV_TIMER
is active: false

close on UV_TIMER
is active: true
is active: true

close on UV_TIMER
is active: false

Will look more into this tomorrow.

indutny · 2015-10-14T23:24:58Z

Here is my patch:

diff --git a/deps/uv/src/win/handle-inl.h b/deps/uv/src/win/handle-inl.h
index 8d0334c..aec64c6 100644
--- a/deps/uv/src/win/handle-inl.h
+++ b/deps/uv/src/win/handle-inl.h
@@ -64,10 +64,6 @@
   do {                                                                  \
     assert(!((handle)->flags & UV__HANDLE_CLOSING));                    \
                                                                         \
-    if (!(((handle)->flags & UV__HANDLE_ACTIVE) &&                      \
-          ((handle)->flags & UV__HANDLE_REF)))                          \
-      uv__active_handle_add((uv_handle_t*) (handle));                   \
-                                                                        \
     (handle)->flags |= UV__HANDLE_CLOSING;                              \
     (handle)->flags &= ~UV__HANDLE_ACTIVE;                              \
   } while (0)
@@ -76,7 +72,6 @@
 #define uv__handle_close(handle)                                        \
   do {                                                                  \
     QUEUE_REMOVE(&(handle)->handle_queue);                              \
-    uv__active_handle_rm((uv_handle_t*) (handle));                      \
                                                                         \
     (handle)->flags |= UV_HANDLE_CLOSED;                                \
                                                                         \

It fixes the test, but I don't know if it is correct.

indutny · 2015-10-14T23:32:01Z

Nah, many tests fail with my patch. We really need @piscisaureus to help us figure out what is the best course of action here

indutny · 2015-10-15T15:03:21Z

After some thinking yesterday, I'm starting to think that uv_timer_t on unix is an outlier here. Everyone else increments active handle count on uv_close, and only timer does not do this on unixes. So, perhaps, windows is the only working platform here :)

The closing timer in this test - is the one from the lists variable in timers.js. When you do .unref(), extra timer gets created for setTimeout() result, and original one is destroyed with .close() (see unenroll)

indutny · 2015-10-15T15:15:24Z

Argh, I'm very wrong. uv_udp_t, uv_check_t, uv_idle_t do not increment it to. Looks like the situation is just different on windows.

indutny · 2015-10-15T16:28:50Z

Alright, I think I have a fix for this PR: indutny@c3df7da . What are your thoughts, @trevnorris ?

trevnorris · 2015-10-15T18:36:01Z

@indutny mind explaining that fix in more detail? don't understand why simply calling to JS would require beforeExit to be emitted again.

indutny · 2015-10-16T01:55:33Z

@trevnorris I feel like test/parallel/test-beforeexit-event is a bit incorrect. setImmediate() triggers within the MakeCallback now, and does not really add any new event-loop entities.

indutny · 2015-10-16T01:56:26Z

@trevnorris overall, it seems that we should define beforeExit very strictly. The doc is very vague on this topic, and I would say that the tests sometimes contradict the current behavior (see that beforeexist-event)

targos · 2015-10-20T18:33:33Z

@indutny is this obsolete with 3eecdf9 ?

indutny · 2015-10-20T18:35:08Z

Yes, thanks!

Fishrock123 added the timers Issues and PRs related to the timers subsystem / setImmediate, setInterval, setTimeout. label Sep 10, 2015

ChALkeR reviewed Sep 10, 2015
View reviewed changes

node,timers: fix beforeExit with unrefed timers

737d9b6

Fishrock123 force-pushed the fix-beforeExit-with-unref branch from 4d8768b to 737d9b6 Compare October 7, 2015 22:31

fixup! test: use strict

01df246

trevnorris reviewed Oct 8, 2015
View reviewed changes

Fishrock123 reviewed Oct 9, 2015
View reviewed changes

!fixup nits, fix test

85854e0

thefourtheye reviewed Oct 9, 2015
View reviewed changes

!fixup make it even better

baaaabf

!fixup don't need this anymore

c358723

!fixup test: fix test-beforeexit-event

5d7262c

Trying to use a net server here is not reasonable, instead try with a file.

Fishrock123 mentioned this pull request Oct 14, 2015

Umbrella Program nodejs/TSC#2

Merged

indutny closed this Oct 20, 2015

trevnorris mentioned this pull request Oct 23, 2015

timer: call list.start regardless new or not #2830

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

node,timers: fix beforeExit with unrefed timers #2795

node,timers: fix beforeExit with unrefed timers #2795

Fishrock123 commented Sep 10, 2015

Fishrock123 commented Sep 10, 2015

ChALkeR Sep 10, 2015

Fishrock123 Sep 10, 2015

Fishrock123 commented Sep 10, 2015

Fishrock123 commented Sep 10, 2015

Fishrock123 commented Oct 7, 2015

trevnorris Oct 8, 2015

trevnorris commented Oct 8, 2015

Fishrock123 Oct 9, 2015

trevnorris Oct 9, 2015

Fishrock123 commented Oct 9, 2015

trevnorris commented Oct 9, 2015

thefourtheye Oct 9, 2015

trevnorris commented Oct 9, 2015

Fishrock123 commented Oct 9, 2015

trevnorris commented Oct 9, 2015

Fishrock123 commented Oct 9, 2015

Fishrock123 commented Oct 10, 2015

trevnorris commented Oct 10, 2015

indutny commented Oct 14, 2015

indutny commented Oct 14, 2015

Fishrock123 commented Oct 14, 2015

trevnorris commented Oct 14, 2015

indutny commented Oct 14, 2015

indutny commented Oct 14, 2015

indutny commented Oct 15, 2015

indutny commented Oct 15, 2015

indutny commented Oct 15, 2015

trevnorris commented Oct 15, 2015

indutny commented Oct 16, 2015

indutny commented Oct 16, 2015

targos commented Oct 20, 2015

indutny commented Oct 20, 2015


		var once = 0;

		process.on('beforeExit', () => {

node,timers: fix beforeExit with unrefed timers #2795

node,timers: fix beforeExit with unrefed timers #2795

Conversation

Fishrock123 commented Sep 10, 2015

Fishrock123 commented Sep 10, 2015

ChALkeR Sep 10, 2015

Choose a reason for hiding this comment

Fishrock123 Sep 10, 2015

Choose a reason for hiding this comment

Fishrock123 commented Sep 10, 2015

Fishrock123 commented Sep 10, 2015

Fishrock123 commented Oct 7, 2015

trevnorris Oct 8, 2015

Choose a reason for hiding this comment

trevnorris commented Oct 8, 2015

Fishrock123 Oct 9, 2015

Choose a reason for hiding this comment

trevnorris Oct 9, 2015

Choose a reason for hiding this comment

Fishrock123 commented Oct 9, 2015

trevnorris commented Oct 9, 2015

thefourtheye Oct 9, 2015

Choose a reason for hiding this comment

trevnorris commented Oct 9, 2015

Fishrock123 commented Oct 9, 2015

trevnorris commented Oct 9, 2015

Fishrock123 commented Oct 9, 2015

Fishrock123 commented Oct 10, 2015

trevnorris commented Oct 10, 2015

indutny commented Oct 14, 2015

indutny commented Oct 14, 2015

Fishrock123 commented Oct 14, 2015

trevnorris commented Oct 14, 2015

indutny commented Oct 14, 2015

indutny commented Oct 14, 2015

indutny commented Oct 15, 2015

indutny commented Oct 15, 2015

indutny commented Oct 15, 2015

trevnorris commented Oct 15, 2015

indutny commented Oct 16, 2015

indutny commented Oct 16, 2015

targos commented Oct 20, 2015

indutny commented Oct 20, 2015