New issue
Advanced search Search tips

Issue 737394 link

Starred by 1 user

Issue metadata

Status: WontFix
Owner:
Closed: Aug 2017
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 2
Type: Bug-Regression



Sign in to add a comment

15.6%-21.3% regression in system_health.common_desktop at 481633:481733

Project Member Reported by sullivan@chromium.org, Jun 28 2017

Issue description

See the link to graphs below.
 
Project Member

Comment 3 by 42576172...@developer.gserviceaccount.com, Jun 28 2017

Cc: alexilin@chromium.org
Owner: alexilin@chromium.org

=== Auto-CCing suspected CL author alexilin@chromium.org ===

Hi alexilin@chromium.org, the bisect results pointed to your CL, please take a look at the
results.


=== BISECT JOB RESULTS ===
Perf regression found with culprit

Suspected Commit
  Author : Alexandr Ilin
  Commit : db57d232f21b4f2b09c362d6fabeb2a2286cd863
  Date   : Thu Jun 22 20:39:52 2017
  Subject: predictors: Replace BrowserThread::DB with TaskScheduler API.

Bisect Details
  Configuration: winx64_10_perf_bisect
  Benchmark    : system_health.common_desktop
  Metric       : timeToFirstMeaningfulPaint_avg/browse_social/browse_social_tumblr_infinite_scroll
  Change       : 38.79% | 1896.69949999 -> 2632.43755556

Revision             Result                  N
chromium@481632      1896.7 +- 4179.34       14      good
chromium@481645      1680.99 +- 2245.24      9       good
chromium@481652      1868.81 +- 3991.21      9       good
chromium@481653      1895.42 +- 4533.1       9       good
chromium@481654      1929.39 +- 2203.92      9       bad       <--
chromium@481655      2073.41 +- 3335.86      9       bad
chromium@481658      1951.97 +- 4194.17      14      bad
chromium@481683      1808.71 +- 2568.79      14      bad
chromium@481733      2632.44 +- 5931.36      9       bad

To Run This Test
  src/tools/perf/run_benchmark -v --browser=release_x64 --output-format=chartjson --upload-results --pageset-repeat=1 --also-run-disabled-tests --story-filter=browse.social.tumblr.infinite.scroll system_health.common_desktop

Debug Info
  https://chromeperf.appspot.com/buildbucket_job_status/8975579700962729712

Is this bisect wrong?
  https://chromeperf.appspot.com/bad_bisect?try_job_id=5306225765384192


| O O | Visit http://www.chromium.org/developers/speed-infra/perf-bug-faq
|  X  | for more information addressing perf regression bugs. For feedback,
| / \ | file a bug with component Speed>Bisection.  Thank you!
Project Member

Comment 5 by 42576172...@developer.gserviceaccount.com, Jun 28 2017


=== BISECT JOB RESULTS ===
Perf regression found with culprit

Suspected Commit
  Author : Alexandr Ilin
  Commit : db57d232f21b4f2b09c362d6fabeb2a2286cd863
  Date   : Thu Jun 22 20:39:52 2017
  Subject: predictors: Replace BrowserThread::DB with TaskScheduler API.

Bisect Details
  Configuration: winx64_10_perf_bisect
  Benchmark    : system_health.common_desktop
  Metric       : timeToFirstMeaningfulPaint_avg/browse_social/browse_social_tumblr_infinite_scroll
  Change       : 49.30% | 1571.84864286 -> 2346.73511111

Revision             Result                  N
chromium@481632      1571.85 +- 2174.76      14      good
chromium@481645      1545.63 +- 2782.64      14      good
chromium@481652      1509.64 +- 1347.19      9       good
chromium@481653      1397.36 +- 641.021      9       good
chromium@481654      1731.83 +- 1523.21      9       bad       <--
chromium@481655      1890.4 +- 2932.38       9       bad
chromium@481658      2076.88 +- 3655.39      9       bad
chromium@481683      1916.46 +- 2418.08      9       bad
chromium@481733      2346.74 +- 4317.88      9       bad

To Run This Test
  src/tools/perf/run_benchmark -v --browser=release_x64 --output-format=chartjson --upload-results --pageset-repeat=1 --also-run-disabled-tests --story-filter=browse.social.tumblr.infinite.scroll system_health.common_desktop

Debug Info
  https://chromeperf.appspot.com/buildbucket_job_status/8975553909705939536

Is this bisect wrong?
  https://chromeperf.appspot.com/bad_bisect?try_job_id=5670723131015168


| O O | Visit http://www.chromium.org/developers/speed-infra/perf-bug-faq
|  X  | for more information addressing perf regression bugs. For feedback,
| / \ | file a bug with component Speed>Bisection.  Thank you!
Project Member

Comment 7 by 42576172...@developer.gserviceaccount.com, Jun 28 2017


=== BISECT JOB RESULTS ===
Perf regression found with culprit

Suspected Commit
  Author : Alexandr Ilin
  Commit : db57d232f21b4f2b09c362d6fabeb2a2286cd863
  Date   : Thu Jun 22 20:39:52 2017
  Subject: predictors: Replace BrowserThread::DB with TaskScheduler API.

Bisect Details
  Configuration: winx64_10_perf_bisect
  Benchmark    : system_health.common_desktop
  Metric       : timeToFirstContentfulPaint_avg/load_media/load_media_dailymotion
  Change       : 55.02% | 1712.79477778 -> 2472.39633333

Revision             Result                  N
chromium@481632      1712.79 +- 1000.84      9      good
chromium@481645      1790.14 +- 1174.48      9      good
chromium@481652      2315.62 +- 5471.2       9      good
chromium@481653      1965.66 +- 2402.21      9      good
chromium@481654      2446.93 +- 3883.42      9      bad       <--
chromium@481655      2302.08 +- 2887.63      9      bad
chromium@481658      2269.34 +- 1917.81      9      bad
chromium@481683      2418.63 +- 2550.39      6      bad
chromium@481733      2472.4 +- 3036.87       6      bad

To Run This Test
  src/tools/perf/run_benchmark -v --browser=release_x64 --output-format=chartjson --upload-results --pageset-repeat=1 --also-run-disabled-tests --story-filter=load.media.dailymotion system_health.common_desktop

Debug Info
  https://chromeperf.appspot.com/buildbucket_job_status/8975533851308099648

Is this bisect wrong?
  https://chromeperf.appspot.com/bad_bisect?try_job_id=5491476294795264


| O O | Visit http://www.chromium.org/developers/speed-infra/perf-bug-faq
|  X  | for more information addressing perf regression bugs. For feedback,
| / \ | file a bug with component Speed>Bisection.  Thank you!
Components: Internals>TaskScheduler
Labels: OS-Windows
Migration of one more sqlite table from DB thread to TaskThread background blocking sequence causes regression. TaskSchedulerBackgroundBlockingWorkers seem to be very busy at startup. Adding one more task to the workers pool postpones the initialization of sqlite_persistent_cookie_store that is necessary for making network requests.

I'm reverting the commit chromium@481654 for now while we're looking how to address this issue. I'm going to start a discussion at chromium-dev soon.
Project Member

Comment 9 by bugdroid1@chromium.org, Jun 28 2017

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

commit b1a98a32e9da2a343a8b9fc9d20a615e36f029d1
Author: Alexandr Ilin <alexilin@chromium.org>
Date: Wed Jun 28 18:49:12 2017

Revert "predictors: Replace BrowserThread::DB with TaskScheduler API."

This reverts commit db57d232f21b4f2b09c362d6fabeb2a2286cd863.

Reason for revert: Perf regression on Win10 startup. See  bug 737394 .

Original change's description:
> predictors: Replace BrowserThread::DB with TaskScheduler API.
> 
> Bug:  689520 
> Change-Id: I7434993ce90e2433f1f19becf6aaefd6fa2dffec
> Reviewed-on: https://chromium-review.googlesource.com/535622
> Reviewed-by: Peter Kasting <pkasting@chromium.org>
> Reviewed-by: Egor Pasko <pasko@chromium.org>
> Reviewed-by: Gabriel Charette <gab@chromium.org>
> Commit-Queue: Alexandr Ilin <alexilin@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#481654}

TBR=pasko@chromium.org,pkasting@chromium.org,gab@chromium.org,alexilin@chromium.org

# Not skipping CQ checks because original CL landed > 1 day ago.

Bug:  689520 ,  737394 
Change-Id: I8e23e3dcb012d6d32bc24a7c97cfd341e1f942a3
Reviewed-on: https://chromium-review.googlesource.com/552997
Reviewed-by: Alexandr Ilin <alexilin@chromium.org>
Commit-Queue: Alexandr Ilin <alexilin@chromium.org>
Cr-Commit-Position: refs/heads/master@{#483080}
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/autocomplete_action_predictor.cc
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/autocomplete_action_predictor_table.cc
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/autocomplete_action_predictor_table.h
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/autocomplete_action_predictor_table_unittest.cc
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/autocomplete_action_predictor_unittest.cc
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/glowplug_key_value_data.h
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/glowplug_key_value_table.h
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/loading_predictor_unittest.cc
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/loading_stats_collector_unittest.cc
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/predictor_database.cc
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/predictor_database.h
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/predictor_database_factory.cc
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/predictor_table_base.cc
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/predictor_table_base.h
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/resource_prefetch_predictor.cc
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/resource_prefetch_predictor.h
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/resource_prefetch_predictor_tables.cc
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/resource_prefetch_predictor_tables.h
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/resource_prefetch_predictor_tables_unittest.cc
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/predictors/resource_prefetch_predictor_unittest.cc
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/ui/views/frame/test_with_browser_view.cc
[modify] https://crrev.com/b1a98a32e9da2a343a8b9fc9d20a615e36f029d1/chrome/browser/ui/views/frame/test_with_browser_view.h

If the initialization of sqlite_persistent_cookie_store is necessary for making network requests, it should not be running at TaskPriority::BACKGROUND.

// User won't notice if this task takes an arbitrarily long time to complete.
BACKGROUND = LOWEST,
https://chromium.googlesource.com/chromium/src/+/dbb94859e4464ee4d6c07bd8c1f0b9b65c55db7a/base/task_scheduler/task_traits.h#26
Project Member

Comment 11 by 42576172...@developer.gserviceaccount.com, Jun 28 2017

 Issue 737391  has been merged into this issue.
Status: Assigned (was: Untriaged)
Copying a part of the analysis from an internal discussion:

It is hard to tell what happens, the hypothesis is that:

* the revert actually improves the metrics (there is a slight movement down)
* 2 points later on the graph the FCP goes up again for a different reason (this
  explains why the dashboard does not see the short duration of the improvement)
* comparing the two traces (just after the revert (=good) and just after the new
  regression (=bad)) is ... interesting
* both good and bad have the same tasks in TaskSchedulerForegroundBlah and
  TaskSchedulerForegroundBlah, but in the bad trace they take longer and consume
  less CPU time
* in the _bad_ trace the navigationStart happens ~100ms earlier supposedly
  causing more contention on the disk (did I mention that performance can be
  counter-intuitive?)
* in the _good_ trace the navigationStart seems to be blocked behind
  DesktopBrowserBackend._WaitForBrowserToComeUp, which polls every 100ms

I am leaning towards blaming the benchmark (system_health.common_desktop) - we
should factor out browser startup from this navigation benchmark better. I think
the least intrusive way to fix this source of randomness is to make sure that
WaitForBrowserToComeUp() delays benchmarking until a few databases are
initialized.

Project Member

Comment 14 by bugdroid1@chromium.org, Aug 16 2017

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

commit 9a16ee7a2e71c6a387def43c56583ad1bf5f41f8
Author: Alexandr Ilin <alexilin@chromium.org>
Date: Wed Aug 16 13:13:34 2017

Reland "predictors: Replace BrowserThread::DB with TaskScheduler API."

This reverts commit b1a98a32e9da2a343a8b9fc9d20a615e36f029d1.

Reason for reland: Predictor is one of the last things left on the DB thread 
and it should be converted to finish the DB thread deprecation. We have a plan
how to address benchmark regression and this change isn't blocked. Affected 
benchmarks have a problem themselves. They supposed to be loading benchmarks 
but they're sensitive to startup-related things during the profile creation. 
(https://crbug.com/746100)

Original change's description:
> Revert "predictors: Replace BrowserThread::DB with TaskScheduler API."
> 
> This reverts commit db57d232f21b4f2b09c362d6fabeb2a2286cd863.
> 
> Reason for revert: Perf regression on Win10 startup. See  bug 737394 .
> 
> Original change's description:
> > predictors: Replace BrowserThread::DB with TaskScheduler API.
> > 
> > Bug:  689520 
> > Change-Id: I7434993ce90e2433f1f19becf6aaefd6fa2dffec
> > Reviewed-on: https://chromium-review.googlesource.com/535622
> > Reviewed-by: Peter Kasting <pkasting@chromium.org>
> > Reviewed-by: Egor Pasko <pasko@chromium.org>
> > Reviewed-by: Gabriel Charette <gab@chromium.org>
> > Commit-Queue: Alexandr Ilin <alexilin@chromium.org>
> > Cr-Commit-Position: refs/heads/master@{#481654}
> 
> TBR=pasko@chromium.org,pkasting@chromium.org,gab@chromium.org,alexilin@chromium.org
> 
> # Not skipping CQ checks because original CL landed > 1 day ago.
> 
> Bug:  689520 ,  737394 
> Change-Id: I8e23e3dcb012d6d32bc24a7c97cfd341e1f942a3
> Reviewed-on: https://chromium-review.googlesource.com/552997
> Reviewed-by: Alexandr Ilin <alexilin@chromium.org>
> Commit-Queue: Alexandr Ilin <alexilin@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#483080}

TBR=pkasting@chromium.org,gab@chromium.org

# Not skipping CQ checks because original CL landed > 1 day ago.

Bug:  689520 ,  737394 
Change-Id: Ib8a8addbb38f7dc65eeede7e5f0b8a5ee105a163
Reviewed-on: https://chromium-review.googlesource.com/616680
Commit-Queue: Alexandr Ilin <alexilin@chromium.org>
Reviewed-by: Egor Pasko <pasko@chromium.org>
Reviewed-by: Alexandr Ilin <alexilin@chromium.org>
Cr-Commit-Position: refs/heads/master@{#494757}
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/autocomplete_action_predictor.cc
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/autocomplete_action_predictor_table.cc
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/autocomplete_action_predictor_table.h
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/autocomplete_action_predictor_table_unittest.cc
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/autocomplete_action_predictor_unittest.cc
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/glowplug_key_value_data.h
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/glowplug_key_value_table.h
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/loading_data_collector_unittest.cc
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/loading_predictor_unittest.cc
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/loading_stats_collector_unittest.cc
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/predictor_database.cc
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/predictor_database.h
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/predictor_database_factory.cc
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/predictor_table_base.cc
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/predictor_table_base.h
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/resource_prefetch_predictor.cc
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/resource_prefetch_predictor.h
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/resource_prefetch_predictor_tables.cc
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/resource_prefetch_predictor_tables.h
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/resource_prefetch_predictor_tables_unittest.cc
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/predictors/resource_prefetch_predictor_unittest.cc
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/ui/views/frame/test_with_browser_view.cc
[modify] https://crrev.com/9a16ee7a2e71c6a387def43c56583ad1bf5f41f8/chrome/browser/ui/views/frame/test_with_browser_view.h

Comment 15 by pasko@chromium.org, Aug 23 2017

Status: WontFix (was: Assigned)
Marking as wontfix since it is a measurement problem. Proposing an improvement in Issue 758191.

Sign in to add a comment