page_cycler_v2 benchmark have onload metrics for only 11 out of 25 pages |
||||||||
Issue descriptionhttps://chromeperf.appspot.com/report?sid=6cd58f7ab062844f56c8bd8abb4429e6c74e6b9732cf058fc26803f98a9acd48 An example page that have fcp metric but not onload metric is www.ign.com page. Here is a trace from that page: https://console.developers.google.com/m/cloudstorage/b/chrome-telemetry-output/o/trace-file-id_47-2016-05-29_14-44-20-36507.html
,
Jun 3 2016
Looks like the next step for this bug is to add logic for typical_25 pages to wait for onload event triggered in https://cs.chromium.org/chromium/src/tools/perf/page_sets/typical_25.py?rcl=0&l=53
,
Jun 3 2016
,
Jun 4 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/7289aea063487fc7f4ff64d8a7ce2c7f7a0e023b commit 7289aea063487fc7f4ff64d8a7ce2c7f7a0e023b Author: nednguyen <nednguyen@google.com> Date: Sat Jun 04 04:57:49 2016 [tools/perf] Make pages in typical_25 page_set to wait for load event to triggered BUG= 617004 Review-Url: https://codereview.chromium.org/2033813005 Cr-Commit-Position: refs/heads/master@{#397905} [modify] https://crrev.com/7289aea063487fc7f4ff64d8a7ce2c7f7a0e023b/tools/perf/page_sets/typical_25.py
,
Jun 6 2016
Annie, we do not get any data on the dashboard after June 3rd, can you check? https://chromeperf.appspot.com/report?sid=4e9483f8e6c08e8a2f6fd63afd61b503497c4bd5369077689119f0a7d18b54db&start_rev=397725&end_rev=397902
,
Jun 6 2016
,
Jun 6 2016
No data because the test is failing: https://build.chromium.org/p/chromium.perf/builders/Android%20Nexus5%20Perf%20%281%29/
,
Jun 6 2016
Oh, thanks for the analysis Annie. It's strange that the single page failure stops the benchmark from having any data at all.
,
Jun 6 2016
Looking at the log, seems like what happens is the telemetry test might be killed by some sort of timeout, hence no data produced at all: [ RUN ] http://money.cnn.com/ (INFO) 2016-06-06 05:03:34,565 cmd_helper._ValidateAndLogCommand:153 [host]> /b/build/slave/Android_Nexus5_Perf__1_/build/src/third_party/catapult/devil/bin/deps/linux2/x86_64/bin/adb -s 0d88c7fd25995e62 shell '( echo -n '"'"'{"trace_config": {"enable_systrace": false, "included_categories": ["loading", "*", "navigation", "blink.user_timing", "blink.console"], "record_mode": "record-as-much-as-possible"}}'"'"' > /data/local/chrome-trace-config.json );echo %$?' (INFO) 2016-06-06 05:03:34,812 tracing_backend.StartTracing:130 Start Tracing Request: {'params': {'transferMode': 'ReturnAsStream', 'traceConfig': {'enableSystrace': False, 'recordMode': 'recordAsMuchAsPossible', 'includedCategories': ['loading', '*', 'navigation', 'blink.user_timing', 'blink.console']}}, 'method': 'Tracing.start'} (INFO) 2016-06-06 05:03:34,826 cache_temperature.EnsurePageCacheTemperature:55 PageCacheTemperature: pcv1-warm (INFO) 2016-06-06 05:03:48,812 cmd_helper._ValidateAndLogCommand:153 [host]> /b/build/slave/Android_Nexus5_Perf__1_/build/src/third_party/catapult/devil/bin/deps/linux2/x86_64/bin/adb -s 0d88c7fd25995e62 shell '( rm -f /data/local/chrome-trace-config.json );echo %$?' <Thread(Thread-1, started 140495195756288)> ProcessRead: proc.stdout finished. <Thread(Thread-1, started 140495195756288)> ProcessRead: cleaning up. <Thread(Thread-2, started daemon 140495187363584)> TimedFlush: Finished <Thread(Thread-1, started 140495195756288)> ProcessRead: finished. exit code (as seen by runtest.py): 255 *Dave: you have any idea what killed the telemetry test run in the middle?
,
Jun 7 2016
,
Jun 7 2016
Kouhei & I look more carefully at the log, we highly suspect that this is a test timed out problem. In https://uberchromegw.corp.google.com/i/chromium.perf/builders/Android%20Nexus5%20Perf%20%281%29/builds/3246/steps/page_cycler_v2.typical_25/logs/stdio the first line of the log is: (INFO) 2016-06-06 13:48:16... & the last one is: (INFO) 2016-06-06 17:08:33... So basically, it took more than 3 hours 20 minutes to run page_cycler_v2.typical_25. For comparison, page_cycler.typical_25 only took about 30 minutes to run in total. Kouhei is looking at the cache preparation logic in pcv2 is to check whether we wait for too long..
,
Jun 7 2016
PCv2 takes about same as much time as PCv1 per page. However, PCv2 seems to be cycling through >389 pages, where as PCv1 cycled 75 pages. Wrong page_set repeat?
,
Jun 7 2016
Page_set repeat was correct. Looks like there is some time out timer in test_runner.py, and a single page_cycler_v2.typical25 run takes >60min. What is happening on https://uberchromegw.corp.google.com/i/chromium.perf/builders/Android%20Nexus5%20Perf%20%281%29/builds/3246/steps/page_cycler_v2.typical_25/logs/stdio 1. The test_runner runs PCv2.typical_25(attempt 1). 2. After 60min, abort test run from timeout. 3. The test_runner tries again. 4. After 60min, abort test run from timeout. 5. The test_runner tries again. 6. Timeout again. Give up.
,
Jun 7 2016
Great detective work, Kouhei!
,
Jun 7 2016
As described in https://codereview.chromium.org/2041253002/ : The issue is that a PCv2 run takes >60min. This is because PCv2 cycles through a URL 6 times (cold -> warm, cold -> warm, cold -> warm), where as PCv2 cycles through a URL 3 times (cold -> warm -> warm) The CL reduces 6x iterations to 4x, which should fix the issue.
,
Jun 7 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/d18e493aeedfcfaebfbf044e3725a5c3aaf3589d commit d18e493aeedfcfaebfbf044e3725a5c3aaf3589d Author: kouhei <kouhei@chromium.org> Date: Tue Jun 07 05:26:30 2016 [PCv2] Reduce page_set repeat 3->2 This CL reduces number of page_set iterations in PCv2, to make the test run fit <60min in slow bots such as "Nexus 5 Perf". Before this CL, PCv2 ran a URL 6 times, where as PCv1 ran a URL 3 times. Which made a single page_cycler_v2.typical25 run take >60min, which caused timeout on the perf bots. BUG= 617004 TBR=nednguyen@google.com Review-Url: https://codereview.chromium.org/2041253002 Cr-Commit-Position: refs/heads/master@{#398233} [modify] https://crrev.com/d18e493aeedfcfaebfbf044e3725a5c3aaf3589d/tools/perf/benchmarks/page_cycler_v2.py
,
Jun 7 2016
I confirmed that this is fixed: https://chromeperf.appspot.com/report?sid=6cd58f7ab062844f56c8bd8abb4429e6c74e6b9732cf058fc26803f98a9acd48 now lists 25 pages |
||||||||
►
Sign in to add a comment |
||||||||
Comment 1 by kouhei@chromium.org
, Jun 3 2016