perf_hooks: fix scheduling regression by apapirovski · Pull Request #18051 · nodejs/node

apapirovski · 2018-01-09T02:09:15Z

Scheduling a PerformanceGCCallback should not keep the event loop alive but due to the recent switch to using the native SetImmediate method, it does. Go back to using uv_async_t and add a regression test.

The reason this was uncovered by the http2 binding is that it takes just long enough to do the GC on all the string constants that it creates that this race condition was triggered. (I finally uncovered this when the problem went away simply by commenting out HTTP_KNOWN_HEADERS(STRING_CONSTANT) in node::http2::Initialize.)

Refs: #18020
Fixes: #18047

Checklist

make -j4 test (UNIX), or vcbuild test (Windows) passes
tests and/or benchmarks are included
commit message follows commit guidelines

Affected core subsystem(s)

perf_hooks, src

apapirovski · 2018-01-09T02:09:40Z

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

jasnell · 2018-01-09T02:14:05Z

cc @addaleax

Scheduling a PerformanceGCCallback should not keep the loop alive but due to the recent switch to using the native SetImmediate method, it does. Go back to using uv_async_t and add a regression test.

addaleax

LGTM

I kind of feel like this would better handled eventually by allowing SetImmediate()s to be unrefed, but I guess that would require somebody to make that happen ;)

addaleax · 2018-01-09T12:46:12Z

+ let didCall = false;
+ process.on('beforeExit', () => {
+ assert(!didCall);
+ didCall = true;


You could just use common.mustCall() on the beforeExit handler instead of tracking via didCall, right?

Nope, that would create an infinite loop of always doing more GC and restarting beforeExit.

jasnell · 2018-01-09T16:23:15Z

@addaleax ... Yes, I agree that having the option of unref'ing the env->SetImmediate() would be ideal long term.

jasnell · 2018-01-09T16:27:39Z

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

MylesBorins · 2018-01-09T17:52:34Z

Failures on plinux

make[2]: Entering directory `/home/iojs/build/workspace/node-test-commit-plinux/nodes/ppcle-ubuntu1404/test/addons-napi/test_warning/build'
CC(target) Release/obj.target/test_warning/test_warning.o
SOLINK_MODULE(target) Release/obj.target/test_warning.node
COPY Release/test_warning.node
CC(target) Release/obj.target/test_warning2/test_warning2.o
SOLINK_MODULE(target) Release/obj.target/test_warning2.node
COPY Release/test_warning2.node
make[2]: Leaving directory `/home/iojs/build/workspace/node-test-commit-plinux/nodes/ppcle-ubuntu1404/test/addons-napi/test_warning/build'
gyp info ok touch test/addons-napi/.buildstamp
make[1]: Leaving directory `/home/iojs/build/workspace/node-test-commit-plinux/nodes/ppcle-ubuntu1404'
make: *** [run-ci] Error 2
Build step 'Execute shell' marked build as failure
Run condition [Always] enabling perform for step [[]]
TAP Reports Processing: START
Looking for TAP results report in workspace using pattern: *.tap
Did not find any matching files. Setting build result to FAILURE.
Checking ^not ok
Jenkins Text Finder: File set '*.tap' is empty
Sending e-mails to: michael_dawson@ca.ibm.com gib@uk.ibm.com
Notifying upstream projects of job completion
Finished: FAILURE

also linuxone

make[2]: Entering directory `/data/iojs/build/workspace/node-test-commit-linuxone/nodes/rhel72-s390x/test/addons-napi/test_warning/build'
CC(target) Release/obj.target/test_warning/test_warning.o
CC(target) Release/obj.target/test_warning2/test_warning2.o
SOLINK_MODULE(target) Release/obj.target/test_warning.node
SOLINK_MODULE(target) Release/obj.target/test_warning2.node
COPY Release/test_warning.node
COPY Release/test_warning2.node
make[2]: Leaving directory `/data/iojs/build/workspace/node-test-commit-linuxone/nodes/rhel72-s390x/test/addons-napi/test_warning/build'
gyp info ok touch test/addons-napi/.buildstamp
make[1]: Leaving directory `/data/iojs/build/workspace/node-test-commit-linuxone/nodes/rhel72-s390x'
make: *** [run-ci] Error 2
Build step 'Execute shell' marked build as failure
Run condition [Always] enabling perform for step [[]]
TAP Reports Processing: START
Looking for TAP results report in workspace using pattern: *.tap
Did not find any matching files. Setting build result to FAILURE.
Checking ^not ok
Jenkins Text Finder: File set 'test*' is empty
Sending e-mails to: michael_dawson@ca.ibm.com gib@uk.ibm.com
Notifying upstream projects of job completion
Finished: FAILURE

jasnell · 2018-01-09T17:54:41Z

linux one rerun: https://ci.nodejs.org/job/node-test-commit-linuxone/11748/

apapirovski · 2018-01-09T17:54:43Z

I do not believe those are related to this. Also, there were two CIs earlier that were both fully successful. This didn't need a third run.

jasnell · 2018-01-09T17:55:07Z

plinux rerun: https://ci.nodejs.org/job/node-test-commit-plinux/14448/

jasnell · 2018-01-09T17:57:17Z

CI is looking good, I'll be getting this landed.

Scheduling a PerformanceGCCallback should not keep the loop alive but due to the recent switch to using the native SetImmediate method, it does. Go back to using uv_async_t and add a regression test. PR-URL: nodejs#18051Fixes: nodejs#18047 Refs: nodejs#18020 Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net>

jasnell · 2018-01-09T18:04:11Z

Landed in ececdd3

Scheduling a PerformanceGCCallback should not keep the loop alive but due to the recent switch to using the native SetImmediate method, it does. Go back to using uv_async_t and add a regression test. PR-URL: nodejs#18051Fixes: nodejs#18047 Refs: nodejs#18020 Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net>

Scheduling a PerformanceGCCallback should not keep the loop alive but due to the recent switch to using the native SetImmediate method, it does. Go back to using uv_async_t and add a regression test. Backport-PR-URL: #18050 PR-URL: #18051Fixes: #18047 Refs: #18020 Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net>

apapirovski · 2018-01-10T02:29:22Z

@addaleax @jasnell FWIW, I've got an initial implementation of unrefed Immediates but I'm currently exploring a few other avenues & some refactoring of how immediates work. Should be able to open a PR in the next couple of days depending on how things go.

Scheduling a PerformanceGCCallback should not keep the loop alive but due to the recent switch to using the native SetImmediate method, it does. Go back to using uv_async_t and add a regression test. Backport-PR-URL: #18050 PR-URL: #18051Fixes: #18047 Refs: #18020 Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net>

Scheduling a PerformanceGCCallback should not keep the loop alive but due to the recent switch to using the native SetImmediate method, it does. Go back to using uv_async_t and add a regression test. PR-URL: #18051Fixes: #18047 Refs: #18020 Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net>

apapirovski requested review from addaleax and jasnell January 9, 2018 02:09

nodejs-github-bot added the c++ Issues and PRs that require attention from people who are familiar with C++. label Jan 9, 2018

perf_hooks: fix scheduling regression
c5cc04f
Scheduling a PerformanceGCCallback should not keep the loop alive but due to the recent switch to using the native SetImmediate method, it does. Go back to using uv_async_t and add a regression test.

apapirovski force-pushed the fix-perf-hooks-gc-regression branch from 469ae0f to c5cc04fCompare January 9, 2018 03:52

jasnell approved these changes Jan 9, 2018
View reviewed changes

jasnell added the fast-track PRs that do not need to wait for 48 hours to land. label Jan 9, 2018

addaleax approved these changes Jan 9, 2018
View reviewed changes

jasnell mentioned this pull request Jan 9, 2018
http2: backport changes to v9.x-staging #18050
Closed
4 tasks

jasnell closed this Jan 9, 2018

apapirovski deleted the fix-perf-hooks-gc-regression branch January 9, 2018 18:06

jasnell mentioned this pull request Jan 9, 2018
http2: use aliased buffer for perf stats, add stats #18020
Closed
4 tasks

MylesBorins mentioned this pull request Jan 10, 2018
v9.4.0 proposal #18069
Merged

MylesBorins added dont-land-on-v6.x labels Jan 24, 2018

MylesBorins added lts-watch-v8.x and removed dont-land-on-v8.x labels Jan 24, 2018

MylesBorins added land-on-v8.x and removed lts-watch-v8.x labels May 22, 2018

MylesBorins mentioned this pull request Jul 9, 2018
v8.12.0 proposal #21593
Merged

Uh oh!

Uh oh!

Conversation

apapirovski commented Jan 9, 2018• edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Checklist

Affected core subsystem(s)

Uh oh!

apapirovski commented Jan 9, 2018• edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

jasnell commented Jan 9, 2018

Uh oh!

addaleax left a comment

Choose a reason for hiding this comment

Uh oh!

addaleaxJan 9, 2018

Choose a reason for hiding this comment

Uh oh!

apapirovskiJan 9, 2018

Choose a reason for hiding this comment

Uh oh!

jasnell commented Jan 9, 2018

Uh oh!

jasnell commented Jan 9, 2018

Uh oh!

MylesBorins commented Jan 9, 2018

Uh oh!

jasnell commented Jan 9, 2018

Uh oh!

apapirovski commented Jan 9, 2018

Uh oh!

jasnell commented Jan 9, 2018

Uh oh!

jasnell commented Jan 9, 2018

Uh oh!

jasnell commented Jan 9, 2018

Uh oh!

apapirovski commented Jan 10, 2018

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

apapirovski commented Jan 9, 2018•
edited
Loading

apapirovski commented Jan 9, 2018•
edited
Loading