New issue
Advanced search Search tips
Note: Color blocks (like █ or █) mean that a user may not be available. Tooltip shows the reason.

Issue 865895 link

Starred by 2 users
Status: Fixed
Owner:
█ nednguyen@chromium.org
Last visit > 30 days ago
Closed: Jul 27
Cc:
█ kbr@chromium.org
brucedaw...@chromium.org
█ nednguyen@chromium.org
erikc...@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 1
Type: Bug



Sign in to add a comment

tracing.RequestMemoryDump call in memory.desktop benchmark always fail on "Win 7 Nvidia GPU Perf" platform

Project Member Reported by nednguyen@chromium.org, Jul 20 
The log is in https://chrome-swarming.appspot.com/task?id=3ece17e32a46a710&refresh=10&show_raw=1

Traceback (most recent call last):
  RunBenchmark at c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\story_runner.py:366
    expectations=expectations, max_num_values=benchmark.MAX_NUM_VALUES)
  Run at c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\story_runner.py:231
    _RunStoryAndProcessErrorIfNeeded(story, results, state, test)
  _RunStoryAndProcessErrorIfNeeded at c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\story_runner.py:125
    state.RunStory(results)
  traced_function at c:\b\s\w\ir\third_party\catapult\common\py_trace_event\py_trace_event\trace_event_impl\decorators.py:75
    return func(*args, **kwargs)
  RunStory at c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\page\shared_page_state.py:310
    self._current_page.Run(self)
  Run at c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\page\__init__.py:99
    self.RunPageInteractions(action_runner)
  RunPageInteractions at c:\b\s\w\ir\tools\perf\page_sets\trivial_sites.py:23
    action_runner.MeasureMemory(deterministic_mode=True)
  traced_function at c:\b\s\w\ir\third_party\catapult\common\py_trace_event\py_trace_event\trace_event_impl\decorators.py:75
    return func(*args, **kwargs)
  MeasureMemory at c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\actions\action_runner.py:160
    dump_id = self.tab.browser.DumpMemory()
  DumpMemory at c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\browser\browser.py:282
    return self._browser_backend.DumpMemory(timeout=timeout)
  traced_function at c:\b\s\w\ir\third_party\catapult\common\py_trace_event\py_trace_event\trace_event_impl\decorators.py:75
    return func(*args, **kwargs)
  DumpMemory at c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\backends\chrome\chrome_browser_backend.py:271
    return self.devtools_client.DumpMemory(timeout=timeout)
  DumpMemory at c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\backends\chrome_inspector\devtools_client_backend.py:489
    return self._tracing_backend.DumpMemory(timeout=timeout)
  DumpMemory at c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\backends\chrome_inspector\tracing_backend.py:223
    'Tracing.requestMemoryDump:\n' + json.dumps(response, indent=2))
TracingUnexpectedResponseException: Inspector returned unexpected response for Tracing.requestMemoryDump:
{
  "id": 0, 
  "error": {
    "message": "Tracing is not started", 
    "code": -32000
  }
}

(from https://ci.chromium.org/buildbot/chromium.perf/Win%207%20Nvidia%20GPU%20Perf/2867)


It worths noting that system_health.memory_desktop always pass on other shard (shard #1), so I wonder if this is some sort of hardware issue with device 'build205-m7'

As this failure is unhandle-able, it crashes the whole benchmark and make all subsequent stories fail (this probably can be fixed)

Erik: since you own memory.desktop benchmark, can you look at this?

Comment 1 by erikc...@chromium.org, Jul 20

Cc: erikc...@chromium.org
Owner: nednguyen@chromium.org
Status: Assigned (was: Untriaged)
This error comes from here: https://cs.chromium.org/chromium/src/content/browser/devtools/protocol/tracing_handler.cc?type=cs&q=%22Tracing+is+not+started%22&sq=package:chromium&g=0&l=542

Theoretically, the only way for this to happen is if tracing was - as the message indicates - never started.

Looking at the logs, it seems like we try to start Chrome multiple times and it (crashes?), but it definitely is not starting tracing. I acquired the minidump but don't know how to symbolize. Figuring that out will probably tell us what's wrong. Back to ned for ysmbolization.
logs_from_telemetry_error.txt
78.1 KB View Download
minidump-2018-07-19_18-52-28-275792.dmp
1.0 MB Download

Comment 2 by nednguyen@chromium.org, Jul 20

Cc: kbr@chromium.org nednguyen@chromium.org
Owner: ----
I don't have a windows machine with me (travelling), so can't help with symbolizing the minidump.

If anyone has an access to windows machine, I think they can just load it into Microsoft Visual Studio (https://www.chromium.org/developers/crash-reports#TOC-Working-with-Minidumps)

+Ken in case he has other tips

Comment 3 by erikc...@chromium.org, Jul 20

Owner: nednguyen@chromium.org
Are you sure we upload symbols for the binaries we're running to the symbol server? 

Being able to symbolize crashes from telemetry seems pretty important. Has this been done before?
Screen Shot 2018-07-20 at 10.06.35 AM.png
57.6 KB View Download

Comment 4 by nednguyen@chromium.org, Jul 20 

Hmhh, I can only vaguely recall this issue. 

Ken: you remember how gpu bots deal with this? The reason I am asking is because gpu tests don't have trouble with symbolize crashes from telemetry at all.

Comment 5 by kbr@chromium.org, Jul 20 

Telemetry provides all of the functionality the GPU bots use, in particular _GetStackFromMinidump called from _InternalSymbolizeMinidump in browser_backend.py:

https://cs.chromium.org/chromium/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome/desktop_browser_backend.py?type=cs&q=_GetStackFromMinidump&sq=package:chromium&g=0&l=524

The Telemetry team also provided a way to symbolize all unsymbolized minidumps which we coded up here:
https://cs.chromium.org/chromium/src/content/test/gpu/gpu_tests/gpu_integration_test.py?type=cs&q=_SymbolizeUn&sq=package:chromium&g=0&l=193

but it looks like we never hooked this up in the GPU tests. If there's a good place to hook up something like this in Telemetry's benchmarks it would help.

(We don't upload binaries from all of the builds to the symbol server but it is possible to download the isolate that ran the benchmarks, and that includes the .pdbs that are necessary to symbolize the minidumps manually. The bot should really do this for convenience though.)
Project Member

Comment 7 by bugdroid1@chromium.org, Jul 25 

The following revision refers to this bug:
  https://chromium.googlesource.com/catapult/+/f79ab3845a7ed723823041b6edf65cd439f7aeaa

commit f79ab3845a7ed723823041b6edf65cd439f7aeaa
Author: Nghia Nguyen <nednguyen@google.com>
Date: Wed Jul 25 02:31:20 2018

Make sure Telemetry browser attempts to log symbolizaztion of all unsymbolized dumps upon test failures

Bug:  chromium:865895 
Change-Id: Ibe80e488dc557ac3421ac18a29f19239cb601998

TBR=kbr@chromium.org

Change-Id: Ibe80e488dc557ac3421ac18a29f19239cb601998
Reviewed-on: https://chromium-review.googlesource.com/1149114
Commit-Queue: Ned Nguyen <nednguyen@google.com>
Reviewed-by: Ned Nguyen <nednguyen@google.com>

[modify] https://crrev.com/f79ab3845a7ed723823041b6edf65cd439f7aeaa/telemetry/telemetry/internal/browser/browser.py
Project Member

Comment 8 by bugdroid1@chromium.org, Jul 25 

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

commit 96c90cc6960f1ba5ea45849016af786760e1dc1d
Author: catapult-chromium-autoroll <catapult-chromium-autoroll@skia-buildbots.google.com.iam.gserviceaccount.com>
Date: Wed Jul 25 03:40:32 2018

Roll src/third_party/catapult 6cf86b3c343e..f79ab3845a7e (1 commits)

https://chromium.googlesource.com/catapult.git/+log/6cf86b3c343e..f79ab3845a7e


git log 6cf86b3c343e..f79ab3845a7e --date=short --no-merges --format='%ad %ae %s'
2018-07-25 nednguyen@google.com Make sure Telemetry browser attempts to log symbolizaztion of all unsymbolized dumps upon test failures


Created with:
  gclient setdep -r src/third_party/catapult@f79ab3845a7e

The AutoRoll server is located here: https://catapult-roll.skia.org

Documentation for the AutoRoller is here:
https://skia.googlesource.com/buildbot/+/master/autoroll/README.md

If the roll is causing failures, please contact the current sheriff, who should
be CC'd on the roll, and stop the roller if necessary.

CQ_INCLUDE_TRYBOTS=luci.chromium.try:android_optional_gpu_tests_rel;luci.chromium.try:linux_optional_gpu_tests_rel;luci.chromium.try:mac_optional_gpu_tests_rel;luci.chromium.try:win_optional_gpu_tests_rel

BUG= chromium:865895 
TBR=sullivan@chromium.org

Change-Id: I0632a93297b85b3e5ca364eb908176c39acf9466
Reviewed-on: https://chromium-review.googlesource.com/1149541
Reviewed-by: catapult-chromium-autoroll <catapult-chromium-autoroll@skia-buildbots.google.com.iam.gserviceaccount.com>
Commit-Queue: catapult-chromium-autoroll <catapult-chromium-autoroll@skia-buildbots.google.com.iam.gserviceaccount.com>
Cr-Commit-Position: refs/heads/master@{#577788}
[modify] https://crrev.com/96c90cc6960f1ba5ea45849016af786760e1dc1d/DEPS

Comment 9 by nednguyen@chromium.org, Jul 25

Owner: erikc...@chromium.org
I added the desymoblized log but seems like it's not useful. The new build failures somehow no longer have minidump included:

(ERROR) 2018-07-25 04:40:42,414 story_runner.ProcessError:100  Unhandleable error. Benchmark run will be interrupted
Traceback (most recent call last):
  File "c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\story_runner.py", line 125, in _RunStoryAndProcessErrorIfNeeded
    state.RunStory(results)
  File "c:\b\s\w\ir\third_party\catapult\common\py_trace_event\py_trace_event\trace_event_impl\decorators.py", line 75, in traced_function
    return func(*args, **kwargs)
  File "c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\page\shared_page_state.py", line 310, in RunStory
    self._current_page.Run(self)
  File "c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\page\__init__.py", line 99, in Run
    self.RunPageInteractions(action_runner)
  File "c:\b\s\w\ir\tools\perf\page_sets\trivial_sites.py", line 23, in RunPageInteractions
    action_runner.MeasureMemory(deterministic_mode=True)
  File "c:\b\s\w\ir\third_party\catapult\common\py_trace_event\py_trace_event\trace_event_impl\decorators.py", line 75, in traced_function
    return func(*args, **kwargs)
  File "c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\actions\action_runner.py", line 160, in MeasureMemory
    dump_id = self.tab.browser.DumpMemory()
  File "c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\browser\browser.py", line 282, in DumpMemory
    return self._browser_backend.DumpMemory(timeout=timeout)
  File "c:\b\s\w\ir\third_party\catapult\common\py_trace_event\py_trace_event\trace_event_impl\decorators.py", line 75, in traced_function
    return func(*args, **kwargs)
  File "c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\backends\chrome\chrome_browser_backend.py", line 271, in DumpMemory
    return self.devtools_client.DumpMemory(timeout=timeout)
  File "c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\backends\chrome_inspector\devtools_client_backend.py", line 489, in DumpMemory
    return self._tracing_backend.DumpMemory(timeout=timeout)
  File "c:\b\s\w\ir\third_party\catapult\telemetry\telemetry\internal\backends\chrome_inspector\tracing_backend.py", line 223, in DumpMemory
    'Tracing.requestMemoryDump:\n' + json.dumps(response, indent=2))
TracingUnexpectedResponseException: Inspector returned unexpected response for Tracing.requestMemoryDump:
{
  "id": 0, 
  "error": {
    "message": "Tracing is not started", 
    "code": -32000
  }
}
(INFO) 2018-07-25 04:40:42,415 browser.DumpStateUponFailure:345  *************** BROWSER STANDARD OUTPUT ***************
(INFO) 2018-07-25 04:40:42,417 browser.DumpStateUponFailure:347  
(INFO) 2018-07-25 04:40:42,417 browser.DumpStateUponFailure:350  *********** END OF BROWSER STANDARD OUTPUT ************
(INFO) 2018-07-25 04:40:42,417 browser.DumpStateUponFailure:352  ********************* BROWSER LOG *********************
(INFO) 2018-07-25 04:40:42,417 browser.DumpStateUponFailure:354  No log file
(INFO) 2018-07-25 04:40:42,417 browser.DumpStateUponFailure:357  ***************** END OF BROWSER LOG ******************
(INFO) 2018-07-25 04:40:42,417 browser.DumpStateUponFailure:360  ********************* SYMBOLIZED MINIDUMP *********************
(INFO) 2018-07-25 04:40:42,417 desktop_browser_backend._GetAllCrashpadMinidumps:316  Found crashpad_database_util
(INFO) 2018-07-25 04:40:42,548 desktop_browser_backend.GetAllMinidumpPaths:505  No minidump found via crashpad_database_util
(INFO) 2018-07-25 04:40:42,549 browser.DumpStateUponFailure:366  ***************** END OF SYMBOLIZED MINIDUMP ******************

This is from https://console.developers.google.com/m/cloudstorage/b/chrome-telemetry-output/o/ac721430-8fff-11e8-92e9-d4ae52d1f5b3

The log did show that Telemetry started Chrome with the trace startup file: '--trace-config-file=c:\\b\\s\\w\\itnfx5fr\\tmpvsjgoe\\chrome-trace-config.json'

Given that this only happen on memory.desktop benchmark, I suspect that this is some sort of bug in Chrome memory tracing.

The only way I think we can move this forward is to try to reproduce the flakiness locally or enable better browser logging.

Reassign to erikchen@

Comment 10 by erikc...@chromium.org, Jul 25

Owner: nednguyen@chromium.org
"""
(INFO) 2018-07-25 04:37:15,440 chrome_browser_backend._GetDevToolsClient:118  Got devtools config: ws://127.0.0.1:51689/devtools/browser/2be60ba8-ca8e-41bf-97cb-41f5178b309f
(INFO) 2018-07-25 04:37:16,486 browser._LogBrowserInfo:99  Browser started (pid=1660).
(INFO) 2018-07-25 04:37:16,486 browser._LogBrowserInfo:102  OS: win win7
(INFO) 2018-07-25 04:37:16,486 browser._LogBrowserInfo:105  Detailed OS version: 6.1.7601
(INFO) 2018-07-25 04:37:21,526 desktop_browser_backend._GetAllCrashpadMinidumps:316  Found crashpad_database_util
(INFO) 2018-07-25 04:37:21,612 desktop_browser_backend.GetStackTrace:492  Minidump found: c:\b\s\w\itnfx5fr\tmpwoesp3\reports\9363defe-c92b-4835-87db-ebb957acdc43.dmp
(INFO) 2018-07-25 04:37:21,614 cloud_storage.Insert:383  Uploading c:\b\s\w\itnfx5fr\tmpwoesp3\reports\9363defe-c92b-4835-87db-ebb957acdc43.dmp to gs://chrome-telemetry-output/minidump-2018-07-25_04-37-21-275991.dmp
(INFO) 2018-07-25 04:40:26,059 desktop_browser_backend._GetAllCrashpadMinidumps:316  Found crashpad_database_util
(ERROR) 2018-07-25 04:40:26,065 browser.__init__:54  Failed with BrowserConnectionGoneException while starting the browser backend.
(INFO) 2018-07-25 04:40:26,065 devtools_client_backend._IsDevToolsAgentAvailable:144  Devtools client not yet ready: [Errno 10054] An existing connection was forcibly closed by the remote host
(INFO) 2018-07-25 04:40:26,065 chrome_tracing_agent.RecordClockSyncMarker:173  No devtools clients for issuing clock sync.
(INFO) 2018-07-25 04:40:26,066 chrome_tracing_agent._CreateTraceConfigFile:283  Trace config file string: {"trace_config": {"excluded_categories": ["*"], "included_categories": ["blink.console", "disabled-by-default-memory-infra"], "memory_dump_config": {"triggers": []}, "record_mode": "record-as-much-as-possible"}}
(INFO) 2018-07-25 04:40:26,068 browser.Close:220  Browser is closed.
(WARNING) 2018-07-25 04:40:26,068 desktop_browser_finder.Create:164  Browser creation failed (attempt 1 of 3), retrying
"""

It looks like there are 2 bugs:
1) The browser is crashing, see minidump above. If we can't symbolize, we can't figure out the problem.

2) The trace config is not correctly being passed to a restarted browser. I believe the problem is that the second restart of the browser is using the same "--trace-config-file" as the first restart of the browser [see log]. However, right before starting the browser the second time, we call chrome_tracing_agent._CreateTraceConfigFile again. This creates a trace config file with a new random path. Presumably this should be passed as the --trace-config-file to the second starting of the browser.

Comment 11 by nednguyen@chromium.org, Jul 25 

Wow, eagle eyes! Thanks for the analysis, I will fix the tracing start option

Comment 12 by nednguyen@chromium.org, Jul 25

Status: Started (was: Assigned)
Project Member

Comment 13 by bugdroid1@chromium.org, Jul 26 

The following revision refers to this bug:
  https://chromium.googlesource.com/catapult/+/56f025948c99133951b166234702ceac671b82c8

commit 56f025948c99133951b166234702ceac671b82c8
Author: Nghia Nguyen <nednguyen@google.com>
Date: Thu Jul 26 00:21:24 2018

Add more logging for debugging browser startup failure

First, this adds more logging to debug why browser startup is flaky.
Second, this adds more logging to figure out which trace startup file is created,
which one is used by the browser on startup, and when it's deleted.

Bug:  chromium:865895 
Change-Id: I5f9728df80e966488289ecd358ff7717ee2a2509

TBR=perezju@chromium.org

Change-Id: I5f9728df80e966488289ecd358ff7717ee2a2509
Reviewed-on: https://chromium-review.googlesource.com/1150676
Reviewed-by: Ned Nguyen <nednguyen@google.com>
Commit-Queue: Ned Nguyen <nednguyen@google.com>

[modify] https://crrev.com/56f025948c99133951b166234702ceac671b82c8/telemetry/telemetry/internal/backends/chrome/desktop_browser_finder.py
[modify] https://crrev.com/56f025948c99133951b166234702ceac671b82c8/telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py
Project Member

Comment 14 by bugdroid1@chromium.org, Jul 26 

The following revision refers to this bug:
  https://chromium.googlesource.com/catapult/+/42016a47fa2b5e8b2bdb90615385a67d16589499

commit 42016a47fa2b5e8b2bdb90615385a67d16589499
Author: Nghia Nguyen <nednguyen@google.com>
Date: Thu Jul 26 01:08:05 2018

Add LogSymbolizedUnsymbolizedMinidumps to fake browser

Bug:  chromium:865895 
Change-Id: Ib09928161d1b5c2f7aeacc5946bbbdb09ce09809
Reviewed-on: https://chromium-review.googlesource.com/1150880
Reviewed-by: Kenneth Russell <kbr@chromium.org>
Commit-Queue: Ned Nguyen <nednguyen@google.com>

[modify] https://crrev.com/42016a47fa2b5e8b2bdb90615385a67d16589499/telemetry/telemetry/testing/fakes/__init__.py
Project Member

Comment 15 by bugdroid1@chromium.org, Jul 26 

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

commit 1e73e7af5257c0fda5383855f2ddc8f4cdff7b59
Author: catapult-chromium-autoroll <catapult-chromium-autoroll@skia-buildbots.google.com.iam.gserviceaccount.com>
Date: Thu Jul 26 04:38:24 2018

Roll src/third_party/catapult c829a63538ba..42016a47fa2b (4 commits)

https://chromium.googlesource.com/catapult.git/+log/c829a63538ba..42016a47fa2b


git log c829a63538ba..42016a47fa2b --date=short --no-merges --format='%ad %ae %s'
2018-07-26 nednguyen@google.com Add LogSymbolizedUnsymbolizedMinidumps to fake browser
2018-07-26 dtu@chromium.org [pinpoint] Add android-pixel2_webview-perf to list of Pinpoint bots.
2018-07-26 nednguyen@google.com Add more logging for debugging browser startup failure
2018-07-25 dtu@chromium.org [pinpoint] Case-insensitive sort for bot list.


Created with:
  gclient setdep -r src/third_party/catapult@42016a47fa2b

The AutoRoll server is located here: https://catapult-roll.skia.org

Documentation for the AutoRoller is here:
https://skia.googlesource.com/buildbot/+/master/autoroll/README.md

If the roll is causing failures, please contact the current sheriff, who should
be CC'd on the roll, and stop the roller if necessary.

CQ_INCLUDE_TRYBOTS=luci.chromium.try:android_optional_gpu_tests_rel;luci.chromium.try:linux_optional_gpu_tests_rel;luci.chromium.try:mac_optional_gpu_tests_rel;luci.chromium.try:win_optional_gpu_tests_rel

BUG= chromium:865895 ,chromium:867592, chromium:865895 
TBR=sullivan@chromium.org

Change-Id: I0440cad159a1b1301e7dbf3c7d103fd92064080b
Reviewed-on: https://chromium-review.googlesource.com/1150376
Reviewed-by: catapult-chromium-autoroll <catapult-chromium-autoroll@skia-buildbots.google.com.iam.gserviceaccount.com>
Commit-Queue: catapult-chromium-autoroll <catapult-chromium-autoroll@skia-buildbots.google.com.iam.gserviceaccount.com>
Cr-Commit-Position: refs/heads/master@{#578205}
[modify] https://crrev.com/1e73e7af5257c0fda5383855f2ddc8f4cdff7b59/DEPS
Project Member

Comment 16 by bugdroid1@chromium.org, Jul 26 

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

commit ae98aee3269d2177de599216432e3dd0c2f4d678
Author: Ned Nguyen <nednguyen@google.com>
Date: Thu Jul 26 07:11:18 2018

Refactor gpu_integration_test to reuse browser.LogSymbolizedUnsymbolizedMinidumps method

TBR=kbr@chromium.org

Bug:  chromium:865895 
Cq-Include-Trybots: luci.chromium.try:android_optional_gpu_tests_rel;luci.chromium.try:linux_optional_gpu_tests_rel;luci.chromium.try:mac_optional_gpu_tests_rel;luci.chromium.try:win_optional_gpu_tests_rel
Change-Id: Idfae761c987bbb1578b9393dceb49eef8c3d0c13
Reviewed-on: https://chromium-review.googlesource.com/1150881
Reviewed-by: Ned Nguyen <nednguyen@google.com>
Commit-Queue: Ned Nguyen <nednguyen@google.com>
Cr-Commit-Position: refs/heads/master@{#578226}
[modify] https://crrev.com/ae98aee3269d2177de599216432e3dd0c2f4d678/content/test/gpu/gpu_tests/gpu_integration_test.py

Comment 17 by nednguyen@chromium.org, Jul 27 

Ok, with https://console.developers.google.com/m/cloudstorage/b/chrome-telemetry-output/o/070fbda1-910b-11e8-b094-d4ae52d1f5b3 we have a clearer picture of what happened.

1) Telemetry generates the trace startup commandline flag for browser using tracing_controller_backend. GetChromeTraceConfigFile()
2) Telemetry tries to start browser
3) Browser crashes (sadly the log in #14 is not the right place, hence it did not capture the symbolized dump of this crash yet)
4) Upon crashing, Browser invokes self.Close(), which invokes tracing_backend.FlushTracing() --> this invokes method to remove the old temporary startup trace & generate a new temporary startup trace file

5) Browser is started again, but using the same commandline flag generated in (1), hence the trace startup file passed to browser commandline no longer exists at this point.
Project Member

Comment 18 by bugdroid1@chromium.org, Jul 27 

The following revision refers to this bug:
  https://chromium.googlesource.com/catapult/+/ac8c0c3138b755a94425d907d5e0eb435d6afb2b

commit ac8c0c3138b755a94425d907d5e0eb435d6afb2b
Author: Nghia Nguyen <nednguyen@google.com>
Date: Fri Jul 27 01:36:17 2018

Log browser state iniside Browser.__init__ upon startup failure

Bug:  chromium:865895 
Change-Id: I964c38c5ee7c65704f0cbbe45554fd321643197d
TBR=perezju@hromium.org
Reviewed-on: https://chromium-review.googlesource.com/1152531
Commit-Queue: Ned Nguyen <nednguyen@google.com>
Reviewed-by: Ned Nguyen <nednguyen@google.com>

[modify] https://crrev.com/ac8c0c3138b755a94425d907d5e0eb435d6afb2b/telemetry/telemetry/internal/browser/browser.py
Project Member

Comment 19 by bugdroid1@chromium.org, Jul 27 

The following revision refers to this bug:
  https://chromium.googlesource.com/catapult/+/a1e31db3c6b70369152765f14268257cf5775c49

commit a1e31db3c6b70369152765f14268257cf5775c49
Author: Nghia Nguyen <nednguyen@google.com>
Date: Fri Jul 27 01:48:47 2018

Regenerate startup args for each time trying to start the desktop browser

Bug:  chromium:865895 
Change-Id: I06121d018219adad5d5146145a28b7842a6844ab

TBR=perezju@chromium.org

Change-Id: I06121d018219adad5d5146145a28b7842a6844ab
Reviewed-on: https://chromium-review.googlesource.com/1152474
Reviewed-by: Ned Nguyen <nednguyen@google.com>
Commit-Queue: Ned Nguyen <nednguyen@google.com>

[modify] https://crrev.com/a1e31db3c6b70369152765f14268257cf5775c49/telemetry/telemetry/internal/backends/chrome/desktop_browser_finder.py
Project Member

Comment 20 by bugdroid1@chromium.org, Jul 27 

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

commit bc5b8d88b6ae4acec0c8f4a7a2c24a38139e5ed7
Author: catapult-chromium-autoroll <catapult-chromium-autoroll@skia-buildbots.google.com.iam.gserviceaccount.com>
Date: Fri Jul 27 03:36:20 2018

Roll src/third_party/catapult 933672b6cfa1..ac8c0c3138b7 (1 commits)

https://chromium.googlesource.com/catapult.git/+log/933672b6cfa1..ac8c0c3138b7


git log 933672b6cfa1..ac8c0c3138b7 --date=short --no-merges --format='%ad %ae %s'
2018-07-27 nednguyen@google.com Log browser state iniside Browser.__init__ upon startup failure


Created with:
  gclient setdep -r src/third_party/catapult@ac8c0c3138b7

The AutoRoll server is located here: https://catapult-roll.skia.org

Documentation for the AutoRoller is here:
https://skia.googlesource.com/buildbot/+/master/autoroll/README.md

If the roll is causing failures, please contact the current sheriff, who should
be CC'd on the roll, and stop the roller if necessary.

CQ_INCLUDE_TRYBOTS=luci.chromium.try:android_optional_gpu_tests_rel;luci.chromium.try:linux_optional_gpu_tests_rel;luci.chromium.try:mac_optional_gpu_tests_rel;luci.chromium.try:win_optional_gpu_tests_rel

BUG= chromium:865895 
TBR=sullivan@chromium.org

Change-Id: I6874a9352991d535b83b4fa8047762a3b3583f83
Reviewed-on: https://chromium-review.googlesource.com/1152271
Reviewed-by: catapult-chromium-autoroll <catapult-chromium-autoroll@skia-buildbots.google.com.iam.gserviceaccount.com>
Commit-Queue: catapult-chromium-autoroll <catapult-chromium-autoroll@skia-buildbots.google.com.iam.gserviceaccount.com>
Cr-Commit-Position: refs/heads/master@{#578530}
[modify] https://crrev.com/bc5b8d88b6ae4acec0c8f4a7a2c24a38139e5ed7/DEPS
Project Member

Comment 21 by bugdroid1@chromium.org, Jul 27 

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

commit 6bbd3cbbe1561f447b6879afff811b2ee0867e11
Author: catapult-chromium-autoroll <catapult-chromium-autoroll@skia-buildbots.google.com.iam.gserviceaccount.com>
Date: Fri Jul 27 05:51:13 2018

Roll src/third_party/catapult ac8c0c3138b7..a1e31db3c6b7 (1 commits)

https://chromium.googlesource.com/catapult.git/+log/ac8c0c3138b7..a1e31db3c6b7


git log ac8c0c3138b7..a1e31db3c6b7 --date=short --no-merges --format='%ad %ae %s'
2018-07-27 nednguyen@google.com Regenerate startup args for each time trying to start the desktop browser


Created with:
  gclient setdep -r src/third_party/catapult@a1e31db3c6b7

The AutoRoll server is located here: https://catapult-roll.skia.org

Documentation for the AutoRoller is here:
https://skia.googlesource.com/buildbot/+/master/autoroll/README.md

If the roll is causing failures, please contact the current sheriff, who should
be CC'd on the roll, and stop the roller if necessary.

CQ_INCLUDE_TRYBOTS=luci.chromium.try:android_optional_gpu_tests_rel;luci.chromium.try:linux_optional_gpu_tests_rel;luci.chromium.try:mac_optional_gpu_tests_rel;luci.chromium.try:win_optional_gpu_tests_rel

BUG= chromium:865895 
TBR=sullivan@chromium.org

Change-Id: I9666a5d8bd09b8eb2765b4f407b5e1c2f2fc77fb
Reviewed-on: https://chromium-review.googlesource.com/1152608
Reviewed-by: catapult-chromium-autoroll <catapult-chromium-autoroll@skia-buildbots.google.com.iam.gserviceaccount.com>
Commit-Queue: catapult-chromium-autoroll <catapult-chromium-autoroll@skia-buildbots.google.com.iam.gserviceaccount.com>
Cr-Commit-Position: refs/heads/master@{#578545}
[modify] https://crrev.com/6bbd3cbbe1561f447b6879afff811b2ee0867e11/DEPS

Comment 22 by nednguyen@chromium.org, Jul 27

Status: Fixed (was: Started)
This is now fixed: https://ci.chromium.org/buildbot/chromium.perf/win-10-perf/63.

Thanks a lot to Erik for the log reading in #10!

I filed a separate bug about the behavior of FlushTracing().

Sadly, we still don't know the cause of the flaky browser startup looking at the log.

Comment 23 by nednguyen@chromium.org, Jul 27 

The bug to fix FlushTracing is in issue 868485
►

Sign in to add a comment