process.nextTick & node::MakeCallback are very bloated

I'm doing some optimizations to an addon and I have found the node::MakeCallback and the accompanying process.nextTick to be a major bottleneck for calling into JS-land. I have looked through the code all the way down to the process._nextTickCallback, or whatever it was called, and it is very obvious the whole idea of "register this function for next tick" is very inefficiently implemented in Node.js.

I have found that if I call from C++ into JS using the pure V8 function call I get almost 2x the throughput, while this brings the problem of not correctly firing the enqueued functions to process.nextTick. So I'm doing a workaround where I only call MakeCallback on the last function call for that iteration (or at least that is somewhat close to what I'm trying to do) and this properly fires the enqueued functions.

It would be nice to have a better control of process.nextTick and when to fire it from native land since the current code is like some kind of "solve-everything-with-dynamic-checks-for-every-possible-scenario" kind of solution. The best idea I have come up with is to MakeCallback into a noop fuction just to get the process.nextTick functions to trigger when I'm done with my iteration.

If addons would get to include the env.h they could use TickInfo to check if there are any enqueued functions and then call env->get_tick_callback()->Call(yada, yada... to take care of that thing more efficiently, or you could just add some new functions to node.h so that addons can check the current number of functions to call, and a function to actually do it.

Or, you could just remove the entire thing and only call the enqueued functions from uv_check_t so that you only do it once per iteration and not once per every single function call.

@trevnorris

cc @trevnorris

Would you mind sharing node version, platform and an example implementation?

I only call MakeCallback on the last function call for that iteration

What is an iteration? MakeCallback() should only be used when you want to run user js code, and when you do, you need to clear the ticks after - its defined behaviour, not doing it breaks the API expectations. Efficiently doing the wrong thing isn't helpful, perhaps you can provide example code or a more concrete example of when you think you can skip the extra work in MakeCallback()? And why in those examples you can't do simply what you suggest, use ->Call() or MakeCallbac() as appropriate?

@alexhultman

@alexhultman whether the docs for next tick are sufficiently detailed is not relevant.

One iteration is one epoll_wait return and handling of its ready fds.

That is not my understanding. An iteration is actually the processing of a single struct epoll_event (and yes, this is not documented, the challenge is describing it without refering to epoll, which isn't used on non-linux). If it wasn't like that, there would be observable-in-js differences in when next tick callbacks are called depending on the size of the epoll_wait output array, and the timing of the events.

Intended behaviour is

event 1
next ticks
event 2
next ticks

Whether epoll_wait returned event1 and event2 in a single call, or two consecutive calls. Your suggestion would result in the next ticks all being bunched at the end, after the two events were both handled.

Or so is my understanding, maybe @bnoordhuis or @saghul will contradict me.

You may find the conversation in nodejs/nan#284 interesting.

@alexhultman

process.nextTick() callbacks bear almost no relation to libuv I/O. They fire whenever node makes a call into the VM but that doesn't need to be due to I/O. Example: timers.

@alexhultman Try batching your calls. That's a good idea whether you use node::MakeCallback() or v8::Function::Call() - the latter isn't exactly cheap either, compared to a regular function call.

remove the entire thing and only call the enqueued functions from uv_check_t so that you only do it once per iteration and not once per every single function call

Too risky. I expect the change in timing would cause considerable ecosystem fallout.

I know Node.js itself is sprinkled with tons of MakeCallback and those could be replaced with pure V8 calls and significantly speed up lots of things.

That's not possible because of domains (i.e., the functionality from the domain module.) The right domain needs to have been entered when calling into JS land.

Little used feature of questionable practicality, you say? I don't disagree but that doesn't mean it can change.

To completely put this to rest, Here is the fully trimmed node::MakeCallback():

Local<Value> MakeCallback(Environment* env,
                          Local<Value> recv,
                          const Local<Function> callback,
                          int argc,
                          Local<Value> argv[]) {
  return callback->Call(recv, argc, argv);
}

And here's the test script:

'use strict';
const addon = require('./build/Release/addon');
const print = process._rawDebug;
const ITER = 1e6;
var cntr = 0;
var t = process.hrtime();

addon.makeCallback({}, () => {}, ITER);

t = process.hrtime(t);
print(((t[0] * 1e9 + t[1]) / ITER).toFixed(1) + ' ns/op');

Run time is ~115 ns/op. We can drop this to ~105ns/op if we change the native add-on code to:

void MakeCallback(const FunctionCallbackInfo<Value>& args) {
  Isolate* isolate = args.GetIsolate();
  Local<Object> ctx = args[0].As<Object>();
  Local<Function> fn = args[1].As<Function>();
  const size_t iter = args[2]->IntegerValue();

  for (size_t i = 0; i < iter; i++) {
    node::MakeCallback(isolate, ctx, fn, 0, nullptr);
  }
}

but you can't do this directly when returning from an async call or else the SealHandleScope will cause the following failure:

FATAL ERROR: v8::HandleScope::CreateHandle() Cannot create a handle without a HandleScope
 1: node::Abort() [/var/projects/node_v6/node]
 2: 0xf3d143 [/var/projects/node_v6/node]
 3: v8::Utils::ReportApiFailure(char const*, char const*) [/var/projects/node_v6/node]
 4: v8::internal::HandleScope::Extend(v8::internal::Isolate*) [/var/projects/node_v6/node]
 5: v8::EscapableHandleScope::EscapableHandleScope(v8::Isolate*) [/var/projects/node_v6/node]
 6: node::MakeCallback(v8::Isolate*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*) [/var/projects/node_v6/node]
 7: bmod::run_makecallback(uv_idle_s*) [/var/projects/tmp/node-basic-module/build/Release/addon.node]

So even if you're only calling Function::Call() you still require a v8::HandleScope.

@alexhultman

@alexhultman I have modified your above comment to remove a single word which was less than ideal to use. As someone who has just poked their head in the thread I urge you to remember we abide by a code of conduct in this repo.

@alexhultman

@alexhultman so far @trevnorris has responded with a lot of technical detail on why MakeCallback takes 140ns and shows how to trip the current number to get to 140ns, he has been very politce and to-the-point about everything and a thank-you would have been nice for that.

As for the async queue I suspect using a cirtular buffer structure with zero (well, O(1) amortized) allocations could improve the speed of draining - this is what bluebird does. Currently using V8's microtask queue is very problematic for the reason Trevvor mentioned.

You want to reduce MakeCallback further? It would be really useful if you provided the following.

What you're doing and why that extra 70ns is prohibitive for you.
A demonstration of how avoiding MakeCallback and using the v8 call directly solve that.

That would go a huge way, and please - enter this discussion in an honest attempt to have a dialogue with the people trying to collaborate with you. No one is shoving you into boxes or not taking your feedback seriously.

@alexhultman

@alexhultman First, it'd be a lot easier to communicate w/ you, and to care about what you're saying, if the entire issue were just posed as "I'm seeing a X ns/op discrepancy between using node::MakeCallback() and using v8::Function::Call() directly. What can we do to improve that?" The excessive use of inflammatory adjectives stating how awful of a job we've done really does nothing to help us want to help you.

Second, you haven't put any effort into actually diagnosing the problem you're reporting. Instead of using demeaning remarks it would be helpful to provide something like provide a perf trace, patches to core you've tried to speed things up, or even a test case. Right now the attitude here only exhibits the desire to release frustration; not to improve code.

Third, yes I found one optimization for one use-case of node::MakeCallback(), but you haven't made any comment on the fact that after reducing all of node::MakeCallback() to return fn->Call(...) it still has 30-40ns overhead. I'd enjoy discussing where this additional overhead comes from, but despite being "pretty much the only Node.js developer who actually tries to improve the overall project" you haven't shown any inclination to make an effort at solving the problem.

Fourth, you're ignoring the fact that the shortcuts you're taking makes your code not "node". Meaning, it doesn't obey the domain module, check for proper v8::Context for appropriate vm support, etc. Instead you're basically using node as a build system for your own V8 embedded code. Will it be slower? Yes, of course. If you'd like to have an argument about what operations we should/shouldn't be doing that's fine. But every operation comes with CPU time, and as a project there are general guards we need to have in place.

I've attempted to be helpful. I have three posts with ample amount of code changes and benchmarks; with the hope they would spur productive discussion as to what else we can do. Below is the disassembled function calls that I've walked through and highlighted what additional steps are taken to execute the function in a minimal case:

Disassembly of user facing `node::MakeCallback()`

->  0xf3ba00 <+0>:   pushq  %rbp
    0xf3ba01 <+1>:   movq   %rsp, %rbp
    0xf3ba04 <+4>:   pushq  %r15
    0xf3ba06 <+6>:   pushq  %r14
    0xf3ba08 <+8>:   pushq  %r13
    0xf3ba0a <+10>:  pushq  %r12
    0xf3ba0c <+12>:  pushq  %rbx
    0xf3ba0d <+13>:  subq   $0x38, %rsp
    0xf3ba11 <+17>:  movq   %r8, -0x50(%rbp)
    0xf3ba15 <+21>:  movl   %ecx, -0x54(%rbp)
    0xf3ba18 <+24>:  movq   %rdx, -0x60(%rbp)
    0xf3ba1c <+28>:  movq   %rsi, %rbx
    0xf3ba1f <+31>:  movq   %rdi, %r14
    0xf3ba22 <+34>:  leaq   -0x48(%rbp), %rdi
    0xf3ba26 <+38>:  movq   %r14, %rsi
    0xf3ba29 <+41>:  callq  0x8ce770                  ; v8::EscapableHandleScope::EscapableHandleScope(v8::Isolate*)
    0xf3ba2e <+46>:  movq   %rbx, %rdi
    0xf3ba31 <+49>:  callq  0x8e2ba0                  ; v8::Object::CreationContext()
+   0xf3ba36 <+54>:  movq   %rax, %r13
+   0xf3ba39 <+57>:  movq   (%r13), %rax
+   0xf3ba3d <+61>:  movq   0x37(%rax), %rax
+   0xf3ba41 <+65>:  movq   0x10f(%rax), %r12
+   0xf3ba48 <+72>:  movq   %r13, %rdi
    0xf3ba4b <+75>:  callq  0x8ce8d0                  ; v8::Context::Enter()
    0xf3ba50 <+80>:  movq   0x878(%r12), %r15
    0xf3ba58 <+88>:  movq   (%r12), %rdi
+   0xf3ba5c <+92>:  callq  0x8d47f0                  ; v8::Isolate::GetCurrentContext()
+   0xf3ba61 <+97>:  testq  %r15, %r15
+   0xf3ba64 <+100>: je     0xf3ba78                  ; <+120>
+   0xf3ba66 <+102>: testq  %rax, %rax
+   0xf3ba69 <+105>: je     0xf3ba78                  ; <+120>
+   0xf3ba6b <+107>: movq   (%r15), %rcx
+   0xf3ba6e <+110>: cmpq   (%rax), %rcx
+   0xf3ba71 <+113>: je     0xf3ba8a                  ; <+138>
+   0xf3ba73 <+115>: jmp    0xf3bb19                  ; <+281>
+   0xf3ba78 <+120>: testq  %r15, %r15
+   0xf3ba7b <+123>: jne    0xf3bb19                  ; <+281>
+   0xf3ba81 <+129>: testq  %rax, %rax
+   0xf3ba84 <+132>: jne    0xf3bb19                  ; <+281>
+   0xf3ba8a <+138>: incq   0x338(%r12)
+   0xf3ba92 <+146>: movq   -0x60(%rbp), %rdi
+   0xf3ba96 <+150>: movq   %rbx, %rsi
+   0xf3ba99 <+153>: movl   -0x54(%rbp), %edx
+   0xf3ba9c <+156>: movq   -0x50(%rbp), %rcx
    0xf3baa0 <+160>: callq  0x8e43a0                  ; v8::Function::Call(v8::Local<v8::Value>, int, v8::Local<v8::Value>*)
+   0xf3baa5 <+165>: movq   0x338(%r12), %rcx
+   0xf3baad <+173>: testq  %rax, %rax
+   0xf3bab0 <+176>: jne    0xf3bacf                  ; <+207>
+   0xf3bab2 <+178>: cmpq   $0x2, %rcx
+   0xf3bab6 <+182>: jb     0xf3bac7                  ; <+199>
+   0xf3bab8 <+184>: decq   %rcx
+   0xf3babb <+187>: movq   %rcx, 0x338(%r12)
+   0xf3bac3 <+195>: xorl   %esi, %esi
+   0xf3bac5 <+197>: jmp    0xf3bae8                  ; <+232>
+   0xf3bac7 <+199>: movq   (%r12), %rax
+   0xf3bacb <+203>: addq   $0x60, %rax
+   0xf3bacf <+207>: decq   %rcx
+   0xf3bad2 <+210>: movq   %rcx, 0x338(%r12)
+   0xf3bada <+218>: movq   (%rax), %rsi
+   0xf3badd <+221>: movq   %r14, %rdi
    0xf3bae0 <+224>: callq  0x8ce6e0                  ; v8::HandleScope::CreateHandle(v8::internal::Isolate*, v8::internal::Object*)
    0xf3bae5 <+229>: movq   %rax, %rsi
    0xf3bae8 <+232>: leaq   -0x48(%rbp), %r14
    0xf3baec <+236>: movq   %r14, %rdi
    0xf3baef <+239>: callq  0x8ce7d0                  ; v8::EscapableHandleScope::Escape(v8::internal::Object**)
    0xf3baf4 <+244>: movq   %rax, %rbx
    0xf3baf7 <+247>: movq   %r13, %rdi
    0xf3bafa <+250>: callq  0x8cea20                  ; v8::Context::Exit()
    0xf3baff <+255>: movq   %r14, %rdi
    0xf3bb02 <+258>: callq  0x8d4060                  ; v8::HandleScope::~HandleScope()

Started to do this in the hope we could find some improvements, but at this point I'm just going to step back. When you've come back with some actual effort to find how things could improve I'll engage in further discussion with you.

my prototype does 260k

I'd love to see that. Have a link?

Did you know Node.js does 30k requests/second while NGINX does 170k?

Ah, mine only does 120k/sec. Probably because we have a different number of threads resolving requests. Unlike node and all, that only uses one thread. :P

@benjamingr

@benjamingr

As for the async queue I suspect using a cirtular buffer structure with zero (well, O(1) amortized) allocations could improve the speed of draining

The nextTickQueue rarely goes over 5 items. My benchmarks have shown that the added complexity of a circular buffer adds more than V8's ability to handle such small arrays. Though I did that back in v0.12 days, so perhaps it's worth revisiting.

But overall the overhead would still be negligible. We have extra overhead of needing to check for things like if more microtasks have been queued during the execution of a nextTick(), wrapping everything in try/finally to properly propagate in the case of an unhandledException, etc. Though even with that execution time sits around 50 ns/op. Which is faster that calling v8::Function::Call().

The nextTickQueue rarely goes over 5 items. My benchmarks have shown that the added complexity of a circular buffer adds more than V8's ability to handle such small arrays. Though I did that back in v0.12 days, so perhaps it's worth revisiting.

Yes, that makes sense. Promises can push a thousand things to the queue and it needs to be 0 allocations so it's almost as fast as synchronous calls and the performance loss is minimal - so a fast promise implementation has to use a better data structure. nextTick deferred things are not nearly as common.

@alexhultman

@alexhultman

I report MakeCallback is a lot slower than V8 function call

We need numbers! Tangible, actionable pieces of information that we can do something about. The entirety of your contribution to this issue could be paraphrased as "MakeCallback extremely slow and bloated. Fix it!" I provided patches, benchmarks and numbers hoping you'd jump in at some point and do the same.

which was shown by my benchmark

For the love, where? You state a mythical benchmark exists but haven't posted a single link or line of code. I have exhaustively written benchmarks for 5 variations of a scenario that you say exists, but refuse to directly demonstrate.

including me "not having anything to back up my claims"

I'm only bringing this up b/c I'm afraid that someone in the future will stumble on this thread and think I actually said that. Please, unless you explicitly state you're paraphrasing, only quote things that have actually been said.

Right, because I was completely unaware that Node.js was single threaded

Sorry. That was just a friendly poke at the phrasing. Not a jab at your understanding of how NGINX works. Thought that'd be conveyed by how blatant the comment was and by the :P at the end, but text does suck for expressing humor. Or, I suck at using text to communicate humor.

@benjamingr

so it's almost as fast as synchronous calls and the performance loss is minimal

Queue'ing may be freaky fast, but don't forget about execution setup. Each microtask has ~60ns overhead as well.

Hey, everyone!

Just a reminder that we all want the same thing: For Node.js to be as awesome as it can be.

In the interest of working together to achieve that common goal, perhaps we can try to avoid loaded words/phrases like bloated or spouting. That's not to say you're incorrect to feel the frustration you feel that makes you want to reach for those types of words. Just, maybe, resist the temptation to reach for them anyway.

On the upside, it looks like there's agreement on at least some of the technical path forward. Maybe we can focus on that and try to put the rancor in the rear-view mirror.

And if I'm coming across a bit too preachy and just making things worse, please ignore me and I'll probably go away.

@alexhultman

@alexhultman

Despite having been called out multiple times for not having anything technical to back it up

You have yet to post any code, stack trace, benchmark graph, etc. to technically backup your claim that it was slow. Were there improvements? Yes, but they were only found after I had written a number of benchmarks and test patches to find what could be improved.

we are already far past the point of no return socially here, our relation is already runied for the future

This is unfortunate. If I retained animosity for every developer I've had a strong disagreement with I'd be one very lonely developer.

@alexhultman

@alexhultman I'm sorry, but after ample attempts to be civil your attitude has constantly been hostile towards healthy development. I'll open another issue with the technical points discussed here for further action.

Navigation Menu

Repository navigation

process.nextTick & node::MakeCallback are very bloated #10101

10 remaining items

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

process.nextTick & node::MakeCallback are very bloated #10101

Description

Activity

Fishrock123 commented on Dec 3, 2016

trevnorris commented on Dec 6, 2016

sam-github commented on Dec 6, 2016

sam-github commented on Dec 7, 2016

sam-github commented on Dec 7, 2016

bnoordhuis commented on Dec 8, 2016

bnoordhuis commented on Dec 8, 2016

10 remaining items

trevnorris commented on Dec 12, 2016

MylesBorins commented on Dec 12, 2016

benjamingr commented on Dec 12, 2016

trevnorris commented on Dec 12, 2016

trevnorris commented on Dec 12, 2016

benjamingr commented on Dec 12, 2016

trevnorris commented on Dec 13, 2016

Trott commented on Dec 13, 2016

trevnorris commented on Dec 13, 2016

trevnorris commented on Dec 13, 2016

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions