New issue
Advanced search Search tips

Issue 786597 link

Starred by 5 users

Issue metadata

Status: Started
Owner:
Cc:
Components:
EstimatedDays: ----
NextAction: 2018-04-12
OS: Windows
Pri: 1
Type: Bug

Blocked on: View detail
issue 684640
issue 874237
issue 850450
issue 888714

Blocking:
issue 855121



Sign in to add a comment

2% of non-idle runtime is spent managing the task queue

Project Member Reported by wittman@chromium.org, Nov 17 2017

Issue description

In continuous profiles of 64.0.3269.0 canary generated by the UMA Sampling Profiler, IncomingTaskQueue::DelayedQueue::Pop() is observed to take 1.3% of non-idle runtime. Nearly all of this time is spent within the call to std::priority_queue<base::PendingTask>::pop(). Flame graph view of these calls: https://uma.googleplex.com/p/chrome/callstacks?sid=e5ade69bdff41d66de96185fa8601cca (and see attached image).

This seems quite expensive. By comparison (during startup) the corresponding call in the GPU process only takes 0.02% of non-idle runtime: https://uma.googleplex.com/p/chrome/callstacks?sid=9f76b325b5a46608a929ff2f9148a679
 
browser-process-delayedqueue-pop.png
176 KB View Download
gpu-process-delayedqueue-pop.png
133 KB View Download
Assigning to Rob since he's been working with this code recently.
Hypothesis: There's probably more delayed tasks running around in the browser than the GPU process making more work for std::pop_heap.
There was bug 716187 on having too many ConnectJob::OnTimeout tasks in delayed queue. Perhaps this is a manifestation of that problem, or a related one?
That could do it. We'd need to inventory what's on the Delayed Task Queue, but I'm not aware of a mechanism that does this.

Comment 5 by gab@chromium.org, Nov 24 2017

I have a design doc to solve #3 : https://docs.google.com/a/chromium.org/document/d/11gcfpL-orj8SWY8bUBa1_ZGe8kPLUcjtGf2_WD7nBKw/edit

I'm still (slowly) working on resolving blockers for it (SequenceLocalStorage usage requires SEEQUENCE_CHECKER checks in all methods which are blocked on a few test which require ScopedTaskEnvironment's and TestBrowserThreadBundle's MOCK_TIME mode to become a thing -- almost there).

I expect to resume faster pace on this when I get back from leave in late December.
Great. I took a look at the IncomingTaskQueue functions more broadly, and we're actually spending 18.6% of non-idle execution just dealing with task management: https://uma.googleplex.com/p/chrome/callstacks?sid=0baf7afa625379274efe238744072f20

This also would seem to support lots of delayed tasks in the browser process. (The corresponding number for the GPU process is 0.45%.)
Labels: Performance-Browser
Bulk adding Performance-Browser label for bugs identified with the UMA Sampling Profiler.
Summary: 19% of non-idle runtime is spent managing the task queue (was: 1.3% of non-idle UI thread runtime is spent in IncomingTaskQueue::DelayedQueue::Pop())
FYI: I took a look at Mac profiles and the issue is even worse there @ 23%.

Comment 9 by gab@chromium.org, Mar 3 2018

NextAction: 2018-03-26
Owner: gab@chromium.org
I'll pick this up as part of resolving https://docs.google.com/a/chromium.org/document/d/11gcfpL-orj8SWY8bUBa1_ZGe8kPLUcjtGf2_WD7nBKw/edit (soon)

Comment 10 by gab@chromium.org, Mar 3 2018

Labels: -Pri-2 M-67 Pri-1
Will be P1 for me in M67.

Comment 11 by gab@chromium.org, Mar 13 2018

Status: Started (was: Assigned)

Comment 12 by gab@chromium.org, Mar 13 2018

Blockedon: 684640
Blocked on issue 684640 (WIP), as enabling cancellation of Timer tasks requires its usage to be sequence-affine (as a few tests are breaking the rules).
The NextAction date has arrived: 2018-03-26

Comment 14 by gab@chromium.org, Mar 26 2018

NextAction: 2018-04-12
Still actively working on it but currentlyfocused on another sampling profiler + BrowserThreads bug (wrapping up, this one is next)
The NextAction date has arrived: 2018-04-12

Comment 16 by gab@chromium.org, Jun 8 2018

Blockedon: 850450
Project Member

Comment 17 by bugdroid1@chromium.org, Jun 9 2018

Project Member

Comment 18 by bugdroid1@chromium.org, Jun 30 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/f93ca115caf2976f5a799b1782aaddfd6544102e

commit f93ca115caf2976f5a799b1782aaddfd6544102e
Author: Gabriel Charette <gab@chromium.org>
Date: Sat Jun 30 05:35:30 2018

[MessageLoop] Add MessageLoop.ScheduledSleep.* metrics.

These metric help evaluate whether scheduled sleeps (especially long
ones) tend to be the cause of the next wakeup or not. This will
influence the upcoming redesign of delayed tasks management.

The time histogram was extended to 14 days since that's the maximum
possible cap we will enforce @  crbug.com/850450#c3 . With 50 buckets
that still yields 7 buckets under 16ms so we get proper resolution
in the fast range too.

This will also, as a side-effect of not doing delayed tasks logic
when ShouldQuitWhenIdle(), result in disabling hi-resolution timers
when the loop is QuitWhenIdle(). Not that this will matter much for power
per this mostly being a test-only operation but always nice to reduce
time spent under hi-res timers.

Bug:  850450 , 786597,  854237 
Change-Id: Ic552a512f534fc04162a3d6b53c6043621bb3fcf
Reviewed-on: https://chromium-review.googlesource.com/1094301
Commit-Queue: Gabriel Charette <gab@chromium.org>
Reviewed-by: François Doray <fdoray@chromium.org>
Reviewed-by: Robert Kaplow <rkaplow@chromium.org>
Cr-Commit-Position: refs/heads/master@{#571763}
[modify] https://crrev.com/f93ca115caf2976f5a799b1782aaddfd6544102e/base/message_loop/message_loop.cc
[modify] https://crrev.com/f93ca115caf2976f5a799b1782aaddfd6544102e/base/message_loop/message_loop.h
[modify] https://crrev.com/f93ca115caf2976f5a799b1782aaddfd6544102e/tools/metrics/histograms/histograms.xml

Project Member

Comment 19 by bugdroid1@chromium.org, Jul 19

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/81626592441ad8517fb6acc8c85e4df4544222e4

commit 81626592441ad8517fb6acc8c85e4df4544222e4
Author: Gabriel Charette <gab@chromium.org>
Date: Thu Jul 19 23:22:46 2018

[MessageLoop] Remove heavy diagnosis metrics and leave others only on UI thread

Addresses  crbug.com/860801  in time for the M69 branch while keeping the
diagnosis signals which will be used to assess future improvements
(MessageLoop.DelayedTaskQueueForUI.PendingTasksCountOnIdle that is).

Removed MessageLoop.DelayedTaskQueue.PostedDelay as we've
learnt everything we needed from this one, that is :
We now know that while 99% of tasks are posted with a delay under 30s,
95% of users post at least one task in every portion of the 0ms-3hours
range at least once per day:
https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.DelayedTaskQueue.PostedDelay&fixupData=true&uniqueUsers=true&showMax=true&filters=platform%2Ceq%2CW%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial

Removed MessageLoop.ScheduledSleep.* metrics as we've also
learnt what we wanted from it, that is :
The maximum sleep a MessageLoop ever completes is 1 hour (and
even then 99% of completed sleeps are under 1 second), all
longer delays are reliably always interrupted.
Win : https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.ScheduledSleep.Completed%2CMessageLoop.ScheduledSleep.Interrupted&fixupData=true&showMax=true&filters=platform%2Ceq%2CM%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
Mac : https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.ScheduledSleep.Completed%2CMessageLoop.ScheduledSleep.Interrupted&fixupData=true&showMax=true&filters=platform%2Ceq%2CM%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
Android : https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.ScheduledSleep.Completed%2CMessageLoop.ScheduledSleep.Interrupted&fixupData=true&showMax=true&filters=platform%2Ceq%2CA%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial

Added a test for MessageLoop.DelayedTaskQueueForUI.PendingTasksCountOnIdle
but it appears to be broken on MacOSX (prior to this CL). Added a note
to investigate on the metric but it shouldn't block this CL which
doesn't make it worse.

R=kylechar@chromium.org, rkaplow@chromium.org

Bug:  860801 ,  850450 , 786597
Change-Id: I7a693886ab4e1b9c8e9fbe8a64d906a95019a609
Reviewed-on: https://chromium-review.googlesource.com/1142589
Commit-Queue: Gabriel Charette <gab@chromium.org>
Reviewed-by: kylechar <kylechar@chromium.org>
Reviewed-by: Robert Kaplow (OOO until 0730) <rkaplow@chromium.org>
Cr-Commit-Position: refs/heads/master@{#576686}
[modify] https://crrev.com/81626592441ad8517fb6acc8c85e4df4544222e4/base/message_loop/incoming_task_queue.cc
[modify] https://crrev.com/81626592441ad8517fb6acc8c85e4df4544222e4/base/message_loop/message_loop.cc
[modify] https://crrev.com/81626592441ad8517fb6acc8c85e4df4544222e4/base/message_loop/message_loop.h
[modify] https://crrev.com/81626592441ad8517fb6acc8c85e4df4544222e4/base/message_loop/message_loop_unittest.cc
[modify] https://crrev.com/81626592441ad8517fb6acc8c85e4df4544222e4/tools/metrics/histograms/histograms.xml

Project Member

Comment 20 by bugdroid1@chromium.org, Jul 23

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/c512937e6b6f6ec01384fbb210401aac0c7f1467

commit c512937e6b6f6ec01384fbb210401aac0c7f1467
Author: Wez <wez@chromium.org>
Date: Mon Jul 23 09:56:44 2018

Revert "[MessageLoop] Remove heavy diagnosis metrics and leave others only on UI thread"

This reverts commit 81626592441ad8517fb6acc8c85e4df4544222e4.

Reason for revert: MetricsOnlyFromUILoops test appears to be flaky (see  https://crbug.com/866299 ).

Original change's description:
> [MessageLoop] Remove heavy diagnosis metrics and leave others only on UI thread
>
> Addresses  crbug.com/860801  in time for the M69 branch while keeping the
> diagnosis signals which will be used to assess future improvements
> (MessageLoop.DelayedTaskQueueForUI.PendingTasksCountOnIdle that is).
>
> Removed MessageLoop.DelayedTaskQueue.PostedDelay as we've
> learnt everything we needed from this one, that is :
> We now know that while 99% of tasks are posted with a delay under 30s,
> 95% of users post at least one task in every portion of the 0ms-3hours
> range at least once per day:
> https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.DelayedTaskQueue.PostedDelay&fixupData=true&uniqueUsers=true&showMax=true&filters=platform%2Ceq%2CW%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
>
> Removed MessageLoop.ScheduledSleep.* metrics as we've also
> learnt what we wanted from it, that is :
> The maximum sleep a MessageLoop ever completes is 1 hour (and
> even then 99% of completed sleeps are under 1 second), all
> longer delays are reliably always interrupted.
> Win : https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.ScheduledSleep.Completed%2CMessageLoop.ScheduledSleep.Interrupted&fixupData=true&showMax=true&filters=platform%2Ceq%2CM%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
> Mac : https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.ScheduledSleep.Completed%2CMessageLoop.ScheduledSleep.Interrupted&fixupData=true&showMax=true&filters=platform%2Ceq%2CM%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
> Android : https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.ScheduledSleep.Completed%2CMessageLoop.ScheduledSleep.Interrupted&fixupData=true&showMax=true&filters=platform%2Ceq%2CA%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
>
> Added a test for MessageLoop.DelayedTaskQueueForUI.PendingTasksCountOnIdle
> but it appears to be broken on MacOSX (prior to this CL). Added a note
> to investigate on the metric but it shouldn't block this CL which
> doesn't make it worse.
>
> R=​kylechar@chromium.org, rkaplow@chromium.org
>
> Bug:  860801 ,  850450 , 786597
> Change-Id: I7a693886ab4e1b9c8e9fbe8a64d906a95019a609
> Reviewed-on: https://chromium-review.googlesource.com/1142589
> Commit-Queue: Gabriel Charette <gab@chromium.org>
> Reviewed-by: kylechar <kylechar@chromium.org>
> Reviewed-by: Robert Kaplow (OOO until 0730) <rkaplow@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#576686}

TBR=gab@chromium.org,rkaplow@chromium.org,erikchen@chromium.org,kylechar@chromium.org

Bug:  860801 ,  850450 , 786597,  866299 
Change-Id: I848621acf9ddbec69d72649d16a459910ffa937e
Reviewed-on: https://chromium-review.googlesource.com/1146300
Commit-Queue: Wez <wez@chromium.org>
Reviewed-by: Wez <wez@chromium.org>
Cr-Commit-Position: refs/heads/master@{#577133}
[modify] https://crrev.com/c512937e6b6f6ec01384fbb210401aac0c7f1467/base/message_loop/incoming_task_queue.cc
[modify] https://crrev.com/c512937e6b6f6ec01384fbb210401aac0c7f1467/base/message_loop/message_loop.cc
[modify] https://crrev.com/c512937e6b6f6ec01384fbb210401aac0c7f1467/base/message_loop/message_loop.h
[modify] https://crrev.com/c512937e6b6f6ec01384fbb210401aac0c7f1467/base/message_loop/message_loop_unittest.cc
[modify] https://crrev.com/c512937e6b6f6ec01384fbb210401aac0c7f1467/tools/metrics/histograms/histograms.xml

Project Member

Comment 21 by bugdroid1@chromium.org, Jul 23

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/5c7b464ca5393510823ad2c2a0262a4eb1460c05

commit 5c7b464ca5393510823ad2c2a0262a4eb1460c05
Author: Gabriel Charette <gab@chromium.org>
Date: Mon Jul 23 20:05:18 2018

Reland "[MessageLoop] Remove heavy diagnosis metrics and leave others only on UI thread"

This reverts commit c512937e6b6f6ec01384fbb210401aac0c7f1467.

Reason for revert: change is correct, fixed test flakiness

Original change's description:
> Revert "[MessageLoop] Remove heavy diagnosis metrics and leave others only on UI thread"
> 
> This reverts commit 81626592441ad8517fb6acc8c85e4df4544222e4.
> 
> Reason for revert: MetricsOnlyFromUILoops test appears to be flaky (see  https://crbug.com/866299 ).
> 
> Original change's description:
> > [MessageLoop] Remove heavy diagnosis metrics and leave others only on UI thread
> >
> > Addresses  crbug.com/860801  in time for the M69 branch while keeping the
> > diagnosis signals which will be used to assess future improvements
> > (MessageLoop.DelayedTaskQueueForUI.PendingTasksCountOnIdle that is).
> >
> > Removed MessageLoop.DelayedTaskQueue.PostedDelay as we've
> > learnt everything we needed from this one, that is :
> > We now know that while 99% of tasks are posted with a delay under 30s,
> > 95% of users post at least one task in every portion of the 0ms-3hours
> > range at least once per day:
> > https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.DelayedTaskQueue.PostedDelay&fixupData=true&uniqueUsers=true&showMax=true&filters=platform%2Ceq%2CW%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
> >
> > Removed MessageLoop.ScheduledSleep.* metrics as we've also
> > learnt what we wanted from it, that is :
> > The maximum sleep a MessageLoop ever completes is 1 hour (and
> > even then 99% of completed sleeps are under 1 second), all
> > longer delays are reliably always interrupted.
> > Win : https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.ScheduledSleep.Completed%2CMessageLoop.ScheduledSleep.Interrupted&fixupData=true&showMax=true&filters=platform%2Ceq%2CM%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
> > Mac : https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.ScheduledSleep.Completed%2CMessageLoop.ScheduledSleep.Interrupted&fixupData=true&showMax=true&filters=platform%2Ceq%2CM%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
> > Android : https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.ScheduledSleep.Completed%2CMessageLoop.ScheduledSleep.Interrupted&fixupData=true&showMax=true&filters=platform%2Ceq%2CA%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
> >
> > Added a test for MessageLoop.DelayedTaskQueueForUI.PendingTasksCountOnIdle
> > but it appears to be broken on MacOSX (prior to this CL). Added a note
> > to investigate on the metric but it shouldn't block this CL which
> > doesn't make it worse.
> >
> > R=​kylechar@chromium.org, rkaplow@chromium.org
> >
> > Bug:  860801 ,  850450 , 786597
> > Change-Id: I7a693886ab4e1b9c8e9fbe8a64d906a95019a609
> > Reviewed-on: https://chromium-review.googlesource.com/1142589
> > Commit-Queue: Gabriel Charette <gab@chromium.org>
> > Reviewed-by: kylechar <kylechar@chromium.org>
> > Reviewed-by: Robert Kaplow (OOO until 0730) <rkaplow@chromium.org>
> > Cr-Commit-Position: refs/heads/master@{#576686}
> 
> TBR=gab@chromium.org,rkaplow@chromium.org,erikchen@chromium.org,kylechar@chromium.org
> 
> Bug:  860801 ,  850450 , 786597,  866299 
> Change-Id: I848621acf9ddbec69d72649d16a459910ffa937e
> Reviewed-on: https://chromium-review.googlesource.com/1146300
> Commit-Queue: Wez <wez@chromium.org>
> Reviewed-by: Wez <wez@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#577133}

TBR=wez@chromium.org,gab@chromium.org,rkaplow@chromium.org,erikchen@chromium.org,kylechar@chromium.org

Change-Id: Idb53da9b8b40b407ece6cf6c81b95bcb7072d76c
No-Presubmit: true
No-Tree-Checks: true
No-Try: true
Bug:  860801 ,  850450 , 786597,  866299 
Reviewed-on: https://chromium-review.googlesource.com/1147360
Reviewed-by: Gabriel Charette <gab@chromium.org>
Commit-Queue: Gabriel Charette <gab@chromium.org>
Cr-Commit-Position: refs/heads/master@{#577228}
[modify] https://crrev.com/5c7b464ca5393510823ad2c2a0262a4eb1460c05/base/message_loop/incoming_task_queue.cc
[modify] https://crrev.com/5c7b464ca5393510823ad2c2a0262a4eb1460c05/base/message_loop/message_loop.cc
[modify] https://crrev.com/5c7b464ca5393510823ad2c2a0262a4eb1460c05/base/message_loop/message_loop.h
[modify] https://crrev.com/5c7b464ca5393510823ad2c2a0262a4eb1460c05/base/message_loop/message_loop_unittest.cc
[modify] https://crrev.com/5c7b464ca5393510823ad2c2a0262a4eb1460c05/tools/metrics/histograms/histograms.xml

Project Member

Comment 22 by bugdroid1@chromium.org, Jul 23

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/771b50f56cd66df43f6fa26bc113147432748255

commit 771b50f56cd66df43f6fa26bc113147432748255
Author: Gabriel Charette <gab@chromium.org>
Date: Mon Jul 23 20:15:56 2018

Revert "Reland "[MessageLoop] Remove heavy diagnosis metrics and leave others only on UI thread""

This reverts commit 5c7b464ca5393510823ad2c2a0262a4eb1460c05.

Reason for revert: oops, didn't mean to auto-CQ PS1.

Original change's description:
> Reland "[MessageLoop] Remove heavy diagnosis metrics and leave others only on UI thread"
> 
> This reverts commit c512937e6b6f6ec01384fbb210401aac0c7f1467.
> 
> Reason for revert: change is correct, fixed test flakiness
> 
> Original change's description:
> > Revert "[MessageLoop] Remove heavy diagnosis metrics and leave others only on UI thread"
> > 
> > This reverts commit 81626592441ad8517fb6acc8c85e4df4544222e4.
> > 
> > Reason for revert: MetricsOnlyFromUILoops test appears to be flaky (see  https://crbug.com/866299 ).
> > 
> > Original change's description:
> > > [MessageLoop] Remove heavy diagnosis metrics and leave others only on UI thread
> > >
> > > Addresses  crbug.com/860801  in time for the M69 branch while keeping the
> > > diagnosis signals which will be used to assess future improvements
> > > (MessageLoop.DelayedTaskQueueForUI.PendingTasksCountOnIdle that is).
> > >
> > > Removed MessageLoop.DelayedTaskQueue.PostedDelay as we've
> > > learnt everything we needed from this one, that is :
> > > We now know that while 99% of tasks are posted with a delay under 30s,
> > > 95% of users post at least one task in every portion of the 0ms-3hours
> > > range at least once per day:
> > > https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.DelayedTaskQueue.PostedDelay&fixupData=true&uniqueUsers=true&showMax=true&filters=platform%2Ceq%2CW%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
> > >
> > > Removed MessageLoop.ScheduledSleep.* metrics as we've also
> > > learnt what we wanted from it, that is :
> > > The maximum sleep a MessageLoop ever completes is 1 hour (and
> > > even then 99% of completed sleeps are under 1 second), all
> > > longer delays are reliably always interrupted.
> > > Win : https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.ScheduledSleep.Completed%2CMessageLoop.ScheduledSleep.Interrupted&fixupData=true&showMax=true&filters=platform%2Ceq%2CM%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
> > > Mac : https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.ScheduledSleep.Completed%2CMessageLoop.ScheduledSleep.Interrupted&fixupData=true&showMax=true&filters=platform%2Ceq%2CM%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
> > > Android : https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.ScheduledSleep.Completed%2CMessageLoop.ScheduledSleep.Interrupted&fixupData=true&showMax=true&filters=platform%2Ceq%2CA%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
> > >
> > > Added a test for MessageLoop.DelayedTaskQueueForUI.PendingTasksCountOnIdle
> > > but it appears to be broken on MacOSX (prior to this CL). Added a note
> > > to investigate on the metric but it shouldn't block this CL which
> > > doesn't make it worse.
> > >
> > > R=​kylechar@chromium.org, rkaplow@chromium.org
> > >
> > > Bug:  860801 ,  850450 , 786597
> > > Change-Id: I7a693886ab4e1b9c8e9fbe8a64d906a95019a609
> > > Reviewed-on: https://chromium-review.googlesource.com/1142589
> > > Commit-Queue: Gabriel Charette <gab@chromium.org>
> > > Reviewed-by: kylechar <kylechar@chromium.org>
> > > Reviewed-by: Robert Kaplow (OOO until 0730) <rkaplow@chromium.org>
> > > Cr-Commit-Position: refs/heads/master@{#576686}
> > 
> > TBR=gab@chromium.org,rkaplow@chromium.org,erikchen@chromium.org,kylechar@chromium.org
> > 
> > Bug:  860801 ,  850450 , 786597,  866299 
> > Change-Id: I848621acf9ddbec69d72649d16a459910ffa937e
> > Reviewed-on: https://chromium-review.googlesource.com/1146300
> > Commit-Queue: Wez <wez@chromium.org>
> > Reviewed-by: Wez <wez@chromium.org>
> > Cr-Commit-Position: refs/heads/master@{#577133}
> 
> TBR=wez@chromium.org,gab@chromium.org,rkaplow@chromium.org,erikchen@chromium.org,kylechar@chromium.org
> 
> Change-Id: Idb53da9b8b40b407ece6cf6c81b95bcb7072d76c
> No-Presubmit: true
> No-Tree-Checks: true
> No-Try: true
> Bug:  860801 ,  850450 , 786597,  866299 
> Reviewed-on: https://chromium-review.googlesource.com/1147360
> Reviewed-by: Gabriel Charette <gab@chromium.org>
> Commit-Queue: Gabriel Charette <gab@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#577228}

TBR=wez@chromium.org,gab@chromium.org,rkaplow@chromium.org,erikchen@chromium.org,kylechar@chromium.org

Change-Id: I29dec465bd2a29c3aa16940664ba5e1d3d005c0e
No-Presubmit: true
No-Tree-Checks: true
No-Try: true
Bug:  860801 ,  850450 , 786597,  866299 
Reviewed-on: https://chromium-review.googlesource.com/1147380
Reviewed-by: Gabriel Charette <gab@chromium.org>
Commit-Queue: Gabriel Charette <gab@chromium.org>
Cr-Commit-Position: refs/heads/master@{#577234}
[modify] https://crrev.com/771b50f56cd66df43f6fa26bc113147432748255/base/message_loop/incoming_task_queue.cc
[modify] https://crrev.com/771b50f56cd66df43f6fa26bc113147432748255/base/message_loop/message_loop.cc
[modify] https://crrev.com/771b50f56cd66df43f6fa26bc113147432748255/base/message_loop/message_loop.h
[modify] https://crrev.com/771b50f56cd66df43f6fa26bc113147432748255/base/message_loop/message_loop_unittest.cc
[modify] https://crrev.com/771b50f56cd66df43f6fa26bc113147432748255/tools/metrics/histograms/histograms.xml

Project Member

Comment 23 by bugdroid1@chromium.org, Jul 24

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/5a4495a48fb32b1faa38b4a0a21b47eddce44ef5

commit 5a4495a48fb32b1faa38b4a0a21b47eddce44ef5
Author: Gabriel Charette <gab@chromium.org>
Date: Tue Jul 24 15:34:01 2018

Reland "[MessageLoop] Remove heavy diagnosis metrics and leave others only on UI thread"

Original CL: https://chromium-review.googlesource.com/c/chromium/src/+/1142589
Reverted for test flakiness on Fuchsia.
Implementation is fine (this is a diagnostic metric -- this change
definitely doesn't make it worse). The test was only added to ensure
proper logging on UI thread only. Made the test more robust in this
reland (see diff vs PS1). If it flakes again, please disable it on flaky
platforms instead of reverting.


Original change's description:

Addresses  crbug.com/860801  in time for the M69 branch while keeping the
diagnosis signals which will be used to assess future improvements
(MessageLoop.DelayedTaskQueueForUI.PendingTasksCountOnIdle that is).

Removed MessageLoop.DelayedTaskQueue.PostedDelay as we've
learnt everything we needed from this one, that is :
We now know that while 99% of tasks are posted with a delay under 30s,
95% of users post at least one task in every portion of the 0ms-3hours
range at least once per day:
https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.DelayedTaskQueue.PostedDelay&fixupData=true&uniqueUsers=true&showMax=true&filters=platform%2Ceq%2CW%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial

Removed MessageLoop.ScheduledSleep.* metrics as we've also
learnt what we wanted from it, that is :
The maximum sleep a MessageLoop ever completes is 1 hour (and
even then 99% of completed sleeps are under 1 second), all
longer delays are reliably always interrupted.
Win : https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.ScheduledSleep.Completed%2CMessageLoop.ScheduledSleep.Interrupted&fixupData=true&showMax=true&filters=platform%2Ceq%2CM%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
Mac : https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.ScheduledSleep.Completed%2CMessageLoop.ScheduledSleep.Interrupted&fixupData=true&showMax=true&filters=platform%2Ceq%2CM%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
Android : https://uma.googleplex.com/histograms?endDate=20180717&dayCount=1&histograms=MessageLoop.ScheduledSleep.Completed%2CMessageLoop.ScheduledSleep.Interrupted&fixupData=true&showMax=true&filters=platform%2Ceq%2CA%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial

Added a test for MessageLoop.DelayedTaskQueueForUI.PendingTasksCountOnIdle
but it appears to be broken on MacOSX (prior to this CL). Added a note
to investigate on the metric but it shouldn't block this CL which
doesn't make it worse.

TBR=wez@chromium.org

Bug:  860801 ,  850450 , 786597,  866299 
Change-Id: Ic0fb2b58780cd595e47b36f97a9ae440bb988225
Reviewed-on: https://chromium-review.googlesource.com/1147400
Commit-Queue: Gabriel Charette <gab@chromium.org>
Reviewed-by: Wez <wez@chromium.org>
Reviewed-by: Gabriel Charette <gab@chromium.org>
Cr-Commit-Position: refs/heads/master@{#577553}
[modify] https://crrev.com/5a4495a48fb32b1faa38b4a0a21b47eddce44ef5/base/message_loop/incoming_task_queue.cc
[modify] https://crrev.com/5a4495a48fb32b1faa38b4a0a21b47eddce44ef5/base/message_loop/message_loop.cc
[modify] https://crrev.com/5a4495a48fb32b1faa38b4a0a21b47eddce44ef5/base/message_loop/message_loop.h
[modify] https://crrev.com/5a4495a48fb32b1faa38b4a0a21b47eddce44ef5/base/message_loop/message_loop_unittest.cc
[modify] https://crrev.com/5a4495a48fb32b1faa38b4a0a21b47eddce44ef5/tools/metrics/histograms/histograms.xml

Blocking: 855121
Blockedon: 874237
Summary: 2% of non-idle runtime is spent managing the task queue (was: 19% of non-idle runtime is spent managing the task queue)
Just realized that the bulk of the time spent in MessageLoopTaskRunner::PostDelayedTask is in MessageLoop::ScheduleWork (i.e. MessageLoop::Controller::DidQueueTask -- issue 874237).

This still leaves the DelayedTaskQueue inefficient (OP of this bug) but it's ~2% of non-idle time lost in managing the queue, not 19% : https://uma.googleplex.com/p/chrome/callstacks/?sid=9e232e2b8262507aace469f2acb76bfe
Blockedon: 888714

Sign in to add a comment