[TaskScheduler] Improve tracing visualization of tasks and worker activity |
|||||||
Issue descriptionA few tracing improvements in mind: 1) Highlight when worker threads are active (currently topmost event is "RunTask") to help identify whether TaskScheduler or kernel is at fault when a thread appears ready and isn't picking up a task. 2) Fix toplevel.flow for TaskScheduler tasks, it's currently completely borked. 3) Should probably move task scheduler task flows to task_scheduler.flow (way too much stuff on toplevel.flow and it makes massive traces which are slow to render and navigate, e.g. bundled with net,ipc,mojo,etc.). 4) Bonus: Beyond scope of TaskScheduler but would be nice if tracing had a way to highlight dead threads. Currently on long traces in can look like there are way too many TaskScheduler workers when in fact it's just because some threads were reclaimed per idleness and later recreated with new IDs per a surge of new work (tracing has one line per thread ID ever to be alive and doesn't highlight dead threads).
,
Feb 12 2018
,
Feb 12 2018
Broadening the scope of this issue.
,
Feb 12 2018
,
Feb 12 2018
,
Feb 12 2018
,
Feb 12 2018
Here's what fixed toplevel.flow for TaskScheduler tasks looks like :)
,
Feb 12 2018
> 4) Bonus: Beyond scope of TaskScheduler but would be nice if tracing had a way to highlight dead threads. > Currently on long traces in can look like there are way too many TaskScheduler workers when in fact it's > just because some threads were reclaimed per idleness and later recreated with new IDs per a surge of > new work (tracing has one line per thread ID ever to be alive and doesn't highlight dead threads). A efficient way to use available space would be to allow a new TaskScheduler thread to reuse the row of a dead TaskScheduler thread in the same pool. Example: TaskSchedulerForegroundWorker ============ [Dead] TaskSchedulerForegroundWorker [Born] ========== Becomes: TaskSchedulerForegroundWorker ============ [Dead] [Born] ==========
,
Feb 12 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/d641a6adecc1dddf67823f2b424b6ebac79bce02 commit d641a6adecc1dddf67823f2b424b6ebac79bce02 Author: Gabriel Charette <gab@chromium.org> Date: Mon Feb 12 20:42:01 2018 Add a trace event when a task scheduler worker is active. Example trace with this enabled: https://drive.google.com/file/d/11si1qvQUhRi1jMPNTzgJpqp3D-yFKOf7/view?usp=sharing Also fix a racy setup order in MemoryDumpManagerTest exercised by this change. R=fdoray@chromium.org Bug: 811035 Change-Id: I328dca43f7b5bfd42bcf1a69b1e191fe41523ade Reviewed-on: https://chromium-review.googlesource.com/913251 Reviewed-by: François Doray <fdoray@chromium.org> Commit-Queue: Gabriel Charette <gab@chromium.org> Cr-Commit-Position: refs/heads/master@{#536177} [modify] https://crrev.com/d641a6adecc1dddf67823f2b424b6ebac79bce02/base/task_scheduler/scheduler_worker.cc [modify] https://crrev.com/d641a6adecc1dddf67823f2b424b6ebac79bce02/base/trace_event/memory_dump_manager_unittest.cc
,
Feb 13 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/afeefc5f0138cda1aa5f1f87e67876dbebcdf7f2 commit afeefc5f0138cda1aa5f1f87e67876dbebcdf7f2 Author: Hajime Hoshi <hajimehoshi@chromium.org> Date: Tue Feb 13 04:10:31 2018 Revert "Add a trace event when a task scheduler worker is active." This reverts commit d641a6adecc1dddf67823f2b424b6ebac79bce02. Reason for revert: This CL causes TSan failures: crbug.com/811482 Original change's description: > Add a trace event when a task scheduler worker is active. > > Example trace with this enabled: https://drive.google.com/file/d/11si1qvQUhRi1jMPNTzgJpqp3D-yFKOf7/view?usp=sharing > > Also fix a racy setup order in MemoryDumpManagerTest exercised by this change. > > R=fdoray@chromium.org > > Bug: 811035 > Change-Id: I328dca43f7b5bfd42bcf1a69b1e191fe41523ade > Reviewed-on: https://chromium-review.googlesource.com/913251 > Reviewed-by: François Doray <fdoray@chromium.org> > Commit-Queue: Gabriel Charette <gab@chromium.org> > Cr-Commit-Position: refs/heads/master@{#536177} TBR=gab@chromium.org,primiano@chromium.org,fdoray@chromium.org Change-Id: I6372620c5cff7b04d44be9909f3123436ee6019c No-Presubmit: true No-Tree-Checks: true No-Try: true Bug: 811035 Reviewed-on: https://chromium-review.googlesource.com/915581 Reviewed-by: Hajime Hoshi <hajimehoshi@chromium.org> Commit-Queue: Hajime Hoshi <hajimehoshi@chromium.org> Cr-Commit-Position: refs/heads/master@{#536256} [modify] https://crrev.com/afeefc5f0138cda1aa5f1f87e67876dbebcdf7f2/base/task_scheduler/scheduler_worker.cc [modify] https://crrev.com/afeefc5f0138cda1aa5f1f87e67876dbebcdf7f2/base/trace_event/memory_dump_manager_unittest.cc
,
Feb 13 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/153eb02201c6bf2eca3eaa26d69de52eba60bc19 commit 153eb02201c6bf2eca3eaa26d69de52eba60bc19 Author: Gabriel Charette <gab@chromium.org> Date: Tue Feb 13 09:01:04 2018 Fix toplevel.flow for TaskScheduler tasks. First TaskTracker wasn't even using a fixed TaskAnnotator instance. Second, it turns out that TaskAnnotator depends on a unique |sequence_num| but TaskScheduler doesn't use nor set PendingTask::sequence_num. While this is unfortunate and a bit of an overreaching assumption, TaskScheduler is the only task system where this isn't true. Thus, it's not worthwhile to refactor how this is done at this time. This CL makes this assumption true for TaskScheduler tasks when tracing is active. Third, it appears there's a bug in TaskAnnotator/TRACE_ID_MANGLE where the IDs aren't cross-process unique as they intend to be. This occasionally still results in weird flow artifacts despite fixing the above issues. Will address this independently. Discussion @ https://groups.google.com/a/chromium.org/d/topic/benchmarking-dev/y_cK75SrevE/discussion Example trace with this CL @ crbug.com/811035#c7 R=fdoray@chromium.org Bug: 811035 Change-Id: I77f3ace2eca2b07f1e74f7f79cb35f6d8077931c Reviewed-on: https://chromium-review.googlesource.com/913950 Commit-Queue: Gabriel Charette <gab@chromium.org> Reviewed-by: François Doray <fdoray@chromium.org> Cr-Commit-Position: refs/heads/master@{#536300} [modify] https://crrev.com/153eb02201c6bf2eca3eaa26d69de52eba60bc19/base/task_scheduler/task.cc [modify] https://crrev.com/153eb02201c6bf2eca3eaa26d69de52eba60bc19/base/task_scheduler/task_tracker.cc [modify] https://crrev.com/153eb02201c6bf2eca3eaa26d69de52eba60bc19/base/task_scheduler/task_tracker.h
,
Feb 13 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/8c1fb16b6c55d7fbce3f2c90b56b70e6966b2290 commit 8c1fb16b6c55d7fbce3f2c90b56b70e6966b2290 Author: Gabriel Charette <gab@chromium.org> Date: Tue Feb 13 10:24:06 2018 Reland "Add a trace event when a task scheduler worker is active." This is a reland of d641a6adecc1dddf67823f2b424b6ebac79bce02. It was reverted per causing data races in MemoryDumpManagerTests as they re-initialized the MemoryDumpManager instance after scheduler workers had been brought up (and the workers using tracing prior to receiving a task -- which previously acted as a sync point -- is now highlighting this initialization race). Original change's description: > Add a trace event when a task scheduler worker is active. > > Example trace with this enabled: https://drive.google.com/file/d/11si1qvQUhRi1jMPNTzgJpqp3D-yFKOf7/view?usp=sharing > > Also fix a racy setup order in MemoryDumpManagerTest exercised by this change. > > R=fdoray@chromium.org > > Bug: 811035 > Change-Id: I328dca43f7b5bfd42bcf1a69b1e191fe41523ade > Reviewed-on: https://chromium-review.googlesource.com/913251 > Reviewed-by: François Doray <fdoray@chromium.org> > Commit-Queue: Gabriel Charette <gab@chromium.org> > Cr-Commit-Position: refs/heads/master@{#536177} Bug: 811035 , 811482 Change-Id: If3a7b1dbfa8d50cec97b7b98e88c68f26f9813ec TBR=fdoray@chromium.org Change-Id: If3a7b1dbfa8d50cec97b7b98e88c68f26f9813ec Reviewed-on: https://chromium-review.googlesource.com/915941 Reviewed-by: Primiano Tucci <primiano@chromium.org> Commit-Queue: Primiano Tucci <primiano@chromium.org> Cr-Commit-Position: refs/heads/master@{#536322} [modify] https://crrev.com/8c1fb16b6c55d7fbce3f2c90b56b70e6966b2290/base/task_scheduler/scheduler_worker.cc [modify] https://crrev.com/8c1fb16b6c55d7fbce3f2c90b56b70e6966b2290/base/trace_event/memory_dump_manager_unittest.cc
,
Mar 1 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/77a419e11de9f4b92a9123cc12a07bc4692e4544 commit 77a419e11de9f4b92a9123cc12a07bc4692e4544 Author: Gabriel Charette <gab@chromium.org> Date: Thu Mar 01 12:47:58 2018 Introduce task_scheduler.flow category. This extracts task_scheduler.flow from toplevel.flow. toplevel.flow has way too many events at the moment and is essentially unusable (results in massive traces which are slow to visualize). Unfortunately the tracing macros result in a static variable that assumes the category never changes (INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO). As such the code in task_annotator.cc cannot be reused to log events to a provided category. Instead TaskAnnotator now supports nullptr to disable trace events and TaskScheduler adds its own trace flow events. Bonus: restricted the scope of the TRACE_EVENT_FLAG_FLOW_IN events such that the event "receiving the task" precedes TaskAnnotator::RunTask instead of overlapping with it. This will make flow arrows line up nicer. R=fdoray@chromium.org, primiano@chromium.org Bug: 811035 Change-Id: I1b4042c225486df0caf6c242f1f111291b2a1101 Reviewed-on: https://chromium-review.googlesource.com/939177 Reviewed-by: François Doray <fdoray@chromium.org> Reviewed-by: Robert Liao <robliao@chromium.org> Commit-Queue: Gabriel Charette <gab@chromium.org> Cr-Commit-Position: refs/heads/master@{#540135} [modify] https://crrev.com/77a419e11de9f4b92a9123cc12a07bc4692e4544/base/debug/task_annotator.cc [modify] https://crrev.com/77a419e11de9f4b92a9123cc12a07bc4692e4544/base/debug/task_annotator.h [modify] https://crrev.com/77a419e11de9f4b92a9123cc12a07bc4692e4544/base/task_scheduler/task_tracker.cc
,
Mar 21 2018
1+2+3 fixed. |
|||||||
►
Sign in to add a comment |
|||||||
Comment 1 by gab@chromium.org
, Feb 12 2018132 KB
132 KB View Download