I filed https://github.com/nodejs/node/issues/19937
On Wed, Apr 11, 2018 at 12:03 PM, Ulan Degenbaev <u...@google.com> wrote: > Thank you, John. > > This looks like an unfortunate interaction of V8 incremental marker with > NodeJS's implementation of v8::Platform. > > The incremental marker posts a 1ms task that does a marking step and > reposts itself (using v8::Platform::CallOnForegroundThread). > > This works well in Chrome, but in NodeJS this results in effectively > non-incremental marking because v8::Platform implementation in NodeJS > drains > <https://github.com/nodejs/node/blob/3d43bce045b39d0ac56b8b8f3f741572ac10c505/src/node_platform.cc#L226> > the foreground queue all at once until the queue becomes empty: > while (std::unique_ptr<Task> task = foreground_tasks_.Pop()) { > did_work = true; > RunForegroundTask(std::move(task)); > } > > Running the incremental marking tasks results in adding a new task to > foreground_tasks_: > void PerIsolatePlatformData::PostTask(std::unique_ptr<Task> task) { > foreground_tasks_.Push(std::move(task)); > uv_async_send(flush_tasks_); > } > > I see two possible fixes: > 1) Limit the task draining loop to only run tasks that were in the queue > at the beginning of the loop. > 2) Add time based heuristics to incremental marker to stop rescheduling > tasks or to alternate delayed tasks with normal tasks. > > I'll check with NodeJS team if option 1 is possible because option 2 seems > a bit hacky. > > Cheers, > Ulan. > > > > > > > > On Wed, Apr 11, 2018 at 11:00 AM, Hannes Payer <hpa...@chromium.org> > wrote: > >> +Ulan Degenbaev <u...@chromium.org> >> >> On Wed, Apr 11, 2018 at 10:57 AM <hpa...@chromium.org> wrote: >> >>> Thanks John for your detailed report. >>> >>> You are right, incremental marking steps should ideally be spread out >>> over the whole program execution. It seems like the incremental marking >>> task is the only task running in the observed trace. Do you have any >>> JavaScript work pending? JavaScript should take turns with incremental >>> marking work. Is your workload somehow reproducible for us? >>> >>> We have some good news for you: V8 6.4 introduces concurrent marking >>> which moves most of the marking work on a concurrent thread. I would be >>> interested in seeing how your workload performance changes with a more >>> recent V8 version. >>> >>> >>> On Wednesday, April 11, 2018 at 10:17:01 AM UTC+2, John Edwards wrote: >>>> >>>> Hi all! Just want to lead with a quick thanks to everyone who makes v8 >>>> happen! It's been a super useful piece of technology for me for many years. >>>> That said, it can still be quite mysterious, and, most recently, I've been >>>> trying to understand a bit more about the incremental marking part of the >>>> garbage collector. >>>> >>>> I'm working on the server for a competitive online game using node.js >>>> (primarily version 8.11.1 with v8 version 6.2.414.50). The server updates >>>> the game state around 100 times a second, and normally takes less than 1ms >>>> per update. Occasionally, though, we were seeing 16-50ms pauses between >>>> frames, which temporarily degraded the player experience. The first suspect >>>> was the garbage collector, but on my initial (incorrect) read, I didn't see >>>> anything taking over a few milliseconds. This log of a mark-sweep pass >>>> appeared to me to only take 2.1ms, for instance: >>>> >>>> [2944:0x356a660] 76591 ms: Mark-sweep 20.2 (40.9) -> 12.5 (40.9) MB, >>>> 2.1 / 0.0 ms (+ 26.1 ms in 18 steps since start of marking, biggest >>>> step 2.3 ms, walltime since start of marking 29 ms) finalize >>>> incremental marking via task GC in old space requested >>>> >>>> After much confusion, I eventually stumbled on the >>>> --trace_incremental_marking flag, which gave the following output: >>>> >>>> [2944:0x356a660] 76562 ms: [IncrementalMarking] Start (idle task): old >>>> generation 19MB, limit 27MB, slack 8MB >>>> [2944:0x356a660] 76562 ms: [IncrementalMarking] Start marking >>>> [2944:0x356a660] 76562 ms: [IncrementalMarking] Running >>>> [2944:0x356a660] 76564 ms: [IncrementalMarking] Step in task 827176 >>>> bytes (827100) in 1.9 >>>> [2944:0x356a660] 76566 ms: [IncrementalMarking] Step in task 827136 >>>> bytes (827100) in 1.9 >>>> [2944:0x356a660] 76567 ms: [IncrementalMarking] Step in task 827216 >>>> bytes (827100) in 1.1 >>>> [2944:0x356a660] 76569 ms: [IncrementalMarking] Step in task 878480 >>>> bytes (827100) in 1.5 >>>> [2944:0x356a660] 76570 ms: [IncrementalMarking] Step in task 827168 >>>> bytes (827100) in 1.1 >>>> [2944:0x356a660] 76571 ms: [IncrementalMarking] Step in task 827184 >>>> bytes (827100) in 1.0 >>>> [2944:0x356a660] 76573 ms: [IncrementalMarking] Step in task 849536 >>>> bytes (827100) in 1.7 >>>> [2944:0x356a660] 76575 ms: [IncrementalMarking] Step in task 827104 >>>> bytes (827100) in 2.2 >>>> [2944:0x356a660] 76576 ms: [IncrementalMarking] Step in task 857840 >>>> bytes (827100) in 1.1 >>>> [2944:0x356a660] 76577 ms: [IncrementalMarking] Step in task 1038576 >>>> bytes (827100) in 0.8 >>>> [2944:0x356a660] 76578 ms: [IncrementalMarking] Step in task 827160 >>>> bytes (827100) in 0.7 >>>> [2944:0x356a660] 76580 ms: [IncrementalMarking] Step in task 827128 >>>> bytes (827100) in 2.0 >>>> [2944:0x356a660] 76582 ms: [IncrementalMarking] Step in task 827112 >>>> bytes (827100) in 2.2 >>>> [2944:0x356a660] 76585 ms: [IncrementalMarking] Step in task 827104 >>>> bytes (827100) in 2.2 >>>> [2944:0x356a660] 76586 ms: [IncrementalMarking] Step in task 829880 >>>> bytes (827100) in 1.0 >>>> [2944:0x356a660] 76587 ms: [IncrementalMarking] Step in task 971384 >>>> bytes (827100) in 1.3 >>>> [2944:0x356a660] 76588 ms: [IncrementalMarking] requesting >>>> finalization of incremental marking. >>>> [2944:0x356a660] 76588 ms: [IncrementalMarking] Step in task 199296 >>>> bytes (827100) in 0.6 >>>> [2944:0x356a660] 76588 ms: [IncrementalMarking] (finalize incremental >>>> marking via task). >>>> [2944:0x356a660] 76588 ms: [IncrementalMarking] Finalize incrementally >>>> round 0, spent 0 ms, marking progress 13. >>>> [2944:0x356a660] 76588 ms: [IncrementalMarking] Black allocation >>>> started >>>> [2944:0x356a660] 76589 ms: [IncrementalMarking] Complete (normal). >>>> [2944:0x356a660] 76589 ms: [IncrementalMarking] Step in task 41240 >>>> bytes (827100) in 0.8 >>>> [2944:0x356a660] 76589 ms: [IncrementalMarking] Stopping: old >>>> generation 19MB, limit 27MB, overshoot 0MB >>>> [2944:0x356a660] 76589 ms: [IncrementalMarking] Black allocation >>>> finished >>>> >>>> ... revealing that incremental marking steps occur consecutively (and, >>>> in this case, blocked execution for 29ms). Since I'd read that incremental >>>> marking was designed to reduce jank when scrolling web pages, I'd assumed >>>> the marking steps would be spaced over time. After quite a lot of >>>> profiling, however, I've never seen control get returned to the program >>>> between the start of incremental marking and completion. >>>> >>>> We were eventually able to work around this by avoiding triggering any >>>> mark-sweeps during rounds of gameplay, but I am curious if this is expected >>>> behavior? Am I missing some sort of flag to tune the priority of the >>>> incremental marker? Game developers are used to working around blocking >>>> garbage collectors like this, so it's not too big an issue, but it would be >>>> a nice bonus if you didn't have to worry about it, and it feels like v8 is >>>> pretty close to getting there! >>>> >>>> Also, apologies if this is more of a node issue. If so, I can take my >>>> question over there. >>>> >>> -- >>> -- >>> v8-users mailing list >>> v8-users@googlegroups.com >>> http://groups.google.com/group/v8-users >>> --- >>> You received this message because you are subscribed to the Google >>> Groups "v8-users" group. >>> To unsubscribe from this group and stop receiving emails from it, send >>> an email to v8-users+unsubscr...@googlegroups.com. >>> For more options, visit https://groups.google.com/d/optout. >>> >> > -- -- v8-users mailing list v8-users@googlegroups.com http://groups.google.com/group/v8-users --- You received this message because you are subscribed to the Google Groups "v8-users" group. To unsubscribe from this group and stop receiving emails from it, send an email to v8-users+unsubscr...@googlegroups.com. For more options, visit https://groups.google.com/d/optout.
