node,timers: fix beforeExit with unrefed timers

[Fishrock123]

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]

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

[ChALkeR]

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.

[Fishrock123]

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

[Fishrock123]

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

And I need to add an actual test :P

[Fishrock123]

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

[Fishrock123]

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

@trevnorris PTAL

[trevnorris]

nit: remove empty line.

[trevnorris]

few nits, but otherwise LGTM.

[Fishrock123]

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

[trevnorris]

naw. looks good as it is.

[Fishrock123]

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

[trevnorris]

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

[thefourtheye]

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

[trevnorris]

@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]

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]

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

[Fishrock123]

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

[Fishrock123]

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]

@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]

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]

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]

@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]

@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]

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]

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]

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]

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]

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

[trevnorris]

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

[indutny]

@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]

@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]

@indutny is this obsolete with 3eecdf9 ?

[indutny]

Yes, thanks!