New issue
Advanced search Search tips

Issue 784206 link

Starred by 4 users

Issue metadata

Status: Fixed
Owner:
Closed: Nov 2017
Cc:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 2
Type: Bug-Regression

Blocked on:
issue 787171

Blocking:
issue 699080



Sign in to add a comment

1%-1.8% regression in media.desktop at 515431:515524

Project Member Reported by crouleau@google.com, Nov 12 2017

Issue description

See the link to graphs below.
 
Project Member

Comment 1 by 42576172...@developer.gserviceaccount.com, Nov 12 2017

All graphs for this bug:
  https://chromeperf.appspot.com/group_report?bug_id=784206

(For debugging:) Original alerts at time of bug-filing:
  https://chromeperf.appspot.com/group_report?sid=6797ef5f35e0440a21c53a9fcd143a0abef96a5a4ef1aebc28a18abc8ca2834e


Bot(s) for this bug's original alert(s):

chromium-rel-win10
chromium-rel-win8-dual
Project Member

Comment 3 by 42576172...@developer.gserviceaccount.com, Nov 13 2017

Cc: alexilin@chromium.org
Owner: alexilin@chromium.org
Status: Assigned (was: Untriaged)

=== 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 : e378a8f40efd70f0f138f16eb4a14a290261da86
  Date   : Fri Nov 10 07:54:20 2017
  Subject: Enable SpeculativePreconnect Field Trial Testing

Bisect Details
  Configuration: winx64_10_perf_bisect
  Benchmark    : media.desktop
  Metric       : memory:chrome:all_processes:reported_by_chrome:malloc:effective_size_avg/video.html?src_crowd.ogg_type_audio
  Change       : 0.96% | 12567448.1429 -> 12687472.0

Revision             Result                  N
chromium@515430      12567448 +- 419879      14      good
chromium@515475      12579294 +- 405568      9       good
chromium@515497      12582538 +- 386901      9       good
chromium@515500      12568337 +- 389217      9       good
chromium@515501      12580727 +- 454498      9       good
chromium@515502      12693267 +- 372236      9       bad       <--
chromium@515503      12777314 +- 984226      9       bad
chromium@515508      12691610 +- 391753      9       bad
chromium@515519      12687472 +- 382229      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=video.html.src.crowd.ogg.type.audio media.desktop

More information on addressing performance regressions:
  http://g.co/ChromePerformanceRegressions

Debug information about this bisect:
  https://chromeperf.appspot.com/buildbucket_job_status/8963094120960215264


For feedback, file a bug with component Speed>Bisection
Project Member

Comment 4 by 42576172...@developer.gserviceaccount.com, Nov 13 2017

Cc: tdresser@google.com
 Issue 784382  has been merged into this issue.
Project Member

Comment 5 by 42576172...@developer.gserviceaccount.com, Nov 13 2017

 Issue 784382  has been merged into this issue.
Status: Started (was: Assigned)
Project Member

Comment 7 by 42576172...@developer.gserviceaccount.com, Nov 13 2017

Cc: tdres...@chromium.org
 Issue 784410  has been merged into this issue.
Project Member

Comment 8 by 42576172...@developer.gserviceaccount.com, Nov 13 2017

 Issue 784361  has been merged into this issue.
Project Member

Comment 9 by 42576172...@developer.gserviceaccount.com, Nov 13 2017

 Issue 784388  has been merged into this issue.
Project Member

Comment 10 by 42576172...@developer.gserviceaccount.com, Nov 13 2017

 Issue 784385  has been merged into this issue.
Project Member

Comment 11 by 42576172...@developer.gserviceaccount.com, Nov 13 2017

 Issue 784361  has been merged into this issue.
Project Member

Comment 12 by 42576172...@developer.gserviceaccount.com, Nov 13 2017

Cc: dalecur...@chromium.org
 Issue 784465  has been merged into this issue.
Project Member

Comment 13 by 42576172...@developer.gserviceaccount.com, Nov 13 2017

 Issue 784361  has been merged into this issue.
Project Member

Comment 14 by 42576172...@developer.gserviceaccount.com, Nov 13 2017

 Issue 784361  has been merged into this issue.
Project Member

Comment 15 by 42576172...@developer.gserviceaccount.com, Nov 14 2017

 Issue 784355  has been merged into this issue.
Blocking: 699080
Cc: lizeb@chromium.org pasko@chromium.org
I'm still looking into this. 

What I've seen so far, some regressions in timing metrics can be explained by the fact, that with the enabled SpeculativePreconnect trial we don't preconnect to the main frame url because the actual navigation comes very shortly.

For example, in "loading.desktop / timeToFirstMeaningfulPaint_avg / cold / AllRecipes" the main page has redirect to the same host, so it makes two requests to load the main page. I would expect that the same socket could be reused for both requests but we close the first socket once we realized that we were redirected, thus we have to wait until the second socket will be opened.
The version of chrome before the patch speculatively opens 2 sockets so the second socket could be used to load a redirected URL.
Trace without the patch: 
https://console.developers.google.com/m/cloudstorage/b/chromium-telemetry/o/AllRecipes_2017-11-13_13-18-56_19490.html
Trace with the patch: 
https://console.developers.google.com/m/cloudstorage/b/chromium-telemetry/o/AllRecipes_2017-11-13_13-34-12_91557.html

The memory regression around 100kB is kind of expected because we keep metadata about all subresources requested by the page in memory to build a historical database. All this data is removed whether after the onload event or after a fixed timeout.
We found several issues with the SpeculativePreconnect feature that cause regressions mainly on Windows platform. They will be addressed shortly. I'm reverting the field trial config change for now and I'll re-enable the field trial testing after all issues are fixed.

I've collected traces with the "netlog" category enabled using this CL: https://crrev.com/c/766348.

The issues fall into three categories:

1. Lack of preconnect to the main frame host in case when the predictor database is empty.
   Preconnect to the main frame host during a navigation is something that we don't do in the new version of predictor. We expected that it wouldn't bring much profit because the connection follows shortly after the hint with a higher priority. As it turned out, there are several cases when preconnect to the main frame host improves the loading time:
   * Main page has a redirect to the same host and it's not using HTTP/2. In that case the browser can load a page faster if it opens two sockets at the beginning. It's a possible situation that the browser wants to issue a request to a redirected page while the first socket is still in use and in this case the browser opens a new socket.
     Before: https://console.developers.google.com/m/cloudstorage/b/chromium-telemetry/o/AllRecipes_2017-11-13_13-18-56_19490.html
     After: https://console.developers.google.com/m/cloudstorage/b/chromium-telemetry/o/AllRecipes_2017-11-13_13-34-12_91557.html
   * There is a long delay between a navigation hint and a navigation start. It could happen if the browser can't start a navigation immediately waiting for some background job to be done (see second item). Following traces illustrate the problem:
     Before: https://console.developers.google.com/m/cloudstorage/b/chromium-telemetry/o/load_news_wikipedia_2017-11-15_11-19-40_7722.html
     After: https://console.developers.google.com/m/cloudstorage/b/chromium-telemetry/o/load_news_wikipedia_2017-11-15_11-33-00_11207.html
     The main frame request is blocked until the sqlite_persistent_cookie_store is uninitialized. But the preconnect isn't blocked by this and it allows to gain ~300ms. 

2. Increased database initialization time.
   This is a known issue that startup db initialization can impact loading metrics in system_health.common_desktop benchmark. In the example above, the main page request is delayed for 1.5 seconds because we wait for initialization of the cookie store. This contributes as a main part of the target metric (which should be loading metric, not a startup one). The SpeculativePreconnect feature initializes one more database on the startup that could be noticeable on benchmarks due to Windows I/O slowness.
   Related bug: https://crbug.com/758191

3. Increased memory consumption.
   We expect that the feature will require extra memory because we're keeping extra data in memory. Anyway, I'm going to look at how we can decrease the memory footprint.
Project Member

Comment 18 by bugdroid1@chromium.org, Nov 16 2017

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

commit 698e803c4335c3e9429f580851a580b18e7daef0
Author: Alexandr Ilin <alexilin@chromium.org>
Date: Thu Nov 16 21:07:36 2017

Revert "Enable SpeculativePreconnect Field Trial Testing"

This reverts commit e378a8f40efd70f0f138f16eb4a14a290261da86.

Reason for revert: Several performance regressions was found. The feature will be re-enabled after all issues are fixed.

Original change's description:
> Enable SpeculativePreconnect Field Trial Testing
> 
> The predictors::kSpeculativePreconnectFeature is explicitly disabled in
> net::Predictor browser tests because the LoadingPredictor if enabled
> intercepts all prefetch and preconnect coming from a renderer.
> 
> WarmupManagerTest.testPreconnect() was expecting two connections to be
> opened but it's not the case for the LoadingPredictor, it opens only
> one connection.
> 
> Bug:  699080 
> Change-Id: I73537c3a59818793e41c5741762fe675a4efa97f
> Reviewed-on: https://chromium-review.googlesource.com/754837
> Reviewed-by: Ted Choc <tedchoc@chromium.org>
> Reviewed-by: Helen Li <xunjieli@chromium.org>
> Reviewed-by: Jesse Doherty <jwd@chromium.org>
> Commit-Queue: Alexandr Ilin <alexilin@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#515502}

TBR=jwd@chromium.org,tedchoc@chromium.org,xunjieli@chromium.org,alexilin@chromium.org

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

Bug:  699080 ,  784206 
Change-Id: I315b11b955b4aee52b6644835d649414507265f4
Reviewed-on: https://chromium-review.googlesource.com/774779
Reviewed-by: Alexandr Ilin <alexilin@chromium.org>
Commit-Queue: Alexandr Ilin <alexilin@chromium.org>
Cr-Commit-Position: refs/heads/master@{#517191}
[modify] https://crrev.com/698e803c4335c3e9429f580851a580b18e7daef0/chrome/android/javatests/src/org/chromium/chrome/browser/WarmupManagerTest.java
[modify] https://crrev.com/698e803c4335c3e9429f580851a580b18e7daef0/chrome/browser/net/predictor_browsertest.cc
[modify] https://crrev.com/698e803c4335c3e9429f580851a580b18e7daef0/testing/variations/fieldtrial_testing_config.json

Status: Fixed (was: Started)
Thanks for looking into this!
Project Member

Comment 21 by 42576172...@developer.gserviceaccount.com, Nov 17 2017


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

Suspected Commit
  Author : Alexandr Ilin
  Commit : e378a8f40efd70f0f138f16eb4a14a290261da86
  Date   : Fri Nov 10 07:54:20 2017
  Subject: Enable SpeculativePreconnect Field Trial Testing

Bisect Details
  Configuration: winx64_high_dpi_perf_bisect
  Benchmark    : loading.desktop
  Metric       : timeToFirstMeaningfulPaint_avg/warm/amazon.co.jp
  Change       : 42.11% | 159.015999995 -> 225.984833337

Revision             Result                  N
chromium@515373      159.016 +- 23.9167      6      good
chromium@515441      165.318 +- 13.4104      6      good
chromium@515475      156.624 +- 20.3417      6      good
chromium@515492      159.95 +- 11.8996       6      good
chromium@515501      152.695 +- 23.851       6      good
chromium@515502      222.574 +- 32.2235      6      bad       <--
chromium@515503      222.62 +- 40.948        6      bad
chromium@515505      217.797 +- 47.2757      6      bad
chromium@515509      225.985 +- 33.5234      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=amazon.co.jp loading.desktop

More information on addressing performance regressions:
  http://g.co/ChromePerformanceRegressions

Debug information about this bisect:
  https://chromeperf.appspot.com/buildbucket_job_status/8962663365864567040


For feedback, file a bug with component Speed>Bisection
Blockedon: 787171
Project Member

Comment 23 by bugdroid1@chromium.org, Nov 22 2017

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

commit 3936606f8e24f49ddf9b8e5462449bae591f92e8
Author: Alexandr Ilin <alexilin@chromium.org>
Date: Wed Nov 22 10:43:00 2017

predictors: Preconnect to the main frame after navigation hints

This CL contains three different changes that are independent but
work together to improve page load timing benchmarks results.

1. Preconnect to the main page for all hint origins including
HintOrigin::NAVIGATION.
2. Check for possible HSTS redirects before preconnecting.
3. Open minimum 2 sockets for the main page. This change requires a
fair amount of plumbing to pass a number of sockets from
LoadingPredictor to PreconnectManager.

Bug:  699080 ,  784206 
Change-Id: I5301a86989d1e2ecaa5197ebcec526e4d3bf4eae
Reviewed-on: https://chromium-review.googlesource.com/778899
Reviewed-by: Benoit L <lizeb@chromium.org>
Commit-Queue: Alexandr Ilin <alexilin@chromium.org>
Cr-Commit-Position: refs/heads/master@{#518600}
[modify] https://crrev.com/3936606f8e24f49ddf9b8e5462449bae591f92e8/chrome/browser/predictors/loading_predictor.cc
[modify] https://crrev.com/3936606f8e24f49ddf9b8e5462449bae591f92e8/chrome/browser/predictors/loading_predictor.h
[modify] https://crrev.com/3936606f8e24f49ddf9b8e5462449bae591f92e8/chrome/browser/predictors/loading_predictor_unittest.cc
[modify] https://crrev.com/3936606f8e24f49ddf9b8e5462449bae591f92e8/chrome/browser/predictors/loading_stats_collector.cc
[modify] https://crrev.com/3936606f8e24f49ddf9b8e5462449bae591f92e8/chrome/browser/predictors/loading_stats_collector_unittest.cc
[modify] https://crrev.com/3936606f8e24f49ddf9b8e5462449bae591f92e8/chrome/browser/predictors/loading_test_util.cc
[modify] https://crrev.com/3936606f8e24f49ddf9b8e5462449bae591f92e8/chrome/browser/predictors/loading_test_util.h
[modify] https://crrev.com/3936606f8e24f49ddf9b8e5462449bae591f92e8/chrome/browser/predictors/preconnect_manager.cc
[modify] https://crrev.com/3936606f8e24f49ddf9b8e5462449bae591f92e8/chrome/browser/predictors/preconnect_manager.h
[modify] https://crrev.com/3936606f8e24f49ddf9b8e5462449bae591f92e8/chrome/browser/predictors/preconnect_manager_unittest.cc
[modify] https://crrev.com/3936606f8e24f49ddf9b8e5462449bae591f92e8/chrome/browser/predictors/resource_prefetch_predictor.cc
[modify] https://crrev.com/3936606f8e24f49ddf9b8e5462449bae591f92e8/chrome/browser/predictors/resource_prefetch_predictor.h
[modify] https://crrev.com/3936606f8e24f49ddf9b8e5462449bae591f92e8/chrome/browser/predictors/resource_prefetch_predictor_unittest.cc

Cc: dtu@chromium.org
 Issue 784359  has been merged into this issue.

Sign in to add a comment