[Telemetry] Make unhandled exception output more useful.

[Telemetry] Make unhandled exception output more useful.

This should help tremendously in diagnosing flake on the bots.

Default format:
---------------------------
Traceback (most recent call last):
  File "tools/perf/run_benchmark", line 23, in <module>
    sys.exit(test_runner.Main())
  File "tools/perf/../telemetry/telemetry/test_runner.py", line 290, in Main
    return command.Run(options, args)
  File "tools/perf/../telemetry/telemetry/test_runner.py", line 198, in Run
    return min(255, self._test().Run(copy.copy(options)))
  File "tools/perf/../telemetry/telemetry/test.py", line 53, in Run
    results = page_runner.Run(test, ps, expectations, options)
  File "tools/perf/../telemetry/telemetry/page/page_runner.py", line 330, in Run
    possible_browser, results, state)
  File "tools/perf/../telemetry/telemetry/page/page_runner.py", line 213, in _PrepareAndRunPage
    credentials_path, page.archive_path)
  File "tools/perf/../telemetry/telemetry/page/page_runner.py", line 54, in StartBrowser
    test.DidStartBrowser(self.browser)
  File "/work/chromium/src/tools/perf/measurements/page_cycler.py", line 71, in DidStartBrowser
    self._memory_metric = memory.MemoryMetric(browser)
  File "/work/chromium/src/tools/perf/metrics/memory.py", line 32, in __init__
    self._start_commit_charge = self._browser.memory_stats['SystemCommitCharge']
  File "tools/perf/../telemetry/telemetry/core/browser.py", line 166, in memory_stats
    result = self._GetStatsCommon(self._platform_backend.GetMemoryStats)
  File "tools/perf/../telemetry/telemetry/core/browser.py", line 99, in _GetStatsCommon
    for child_pid in self._platform_backend.GetChildPids(browser_pid):
  File "tools/perf/../telemetry/telemetry/core/platform/posix_platform_backend.py", line 44, in GetChildPids
    return proc_util.GetChildPids(processes, pid)
  File "tools/perf/../telemetry/telemetry/core/platform/proc_util.py", line 86, in GetChildPids
    for foo, curr_pid, curr_ppid, state in processes:
ValueError: need more than 3 values to unpack
---------------------------

New format:
---------------------------
Traceback (most recent call last):
  <module> at tools/perf/run_benchmark:23
    sys.exit(test_runner.Main())
  Main at tools/telemetry/telemetry/test_runner.py:303
    return command.Run(options, args)
  Run at tools/telemetry/telemetry/test_runner.py:211
    return min(255, self._test().Run(copy.copy(options)))
  Run at tools/telemetry/telemetry/test.py:53
    results = page_runner.Run(test, ps, expectations, options)
  Run at tools/telemetry/telemetry/page/page_runner.py:330
    possible_browser, results, state)
  _PrepareAndRunPage at tools/telemetry/telemetry/page/page_runner.py:213
    credentials_path, page.archive_path)
  StartBrowser at tools/telemetry/telemetry/page/page_runner.py:54
    test.DidStartBrowser(self.browser)
  DidStartBrowser at tools/perf/measurements/page_cycler.py:71
    self._memory_metric = memory.MemoryMetric(browser)
  __init__ at tools/perf/metrics/memory.py:32
    self._start_commit_charge = self._browser.memory_stats['SystemCommitCharge']
  memory_stats at tools/telemetry/telemetry/core/browser.py:166
    result = self._GetStatsCommon(self._platform_backend.GetMemoryStats)
  _GetStatsCommon at tools/telemetry/telemetry/core/browser.py:99
    for child_pid in self._platform_backend.GetChildPids(browser_pid):
  GetChildPids at tools/telemetry/telemetry/core/platform/posix_platform_backend.py:44
    return proc_util.GetChildPids(processes, pid)
  GetChildPids at tools/telemetry/telemetry/core/platform/proc_util.py:86
    for foo, curr_pid, curr_ppid, state in processes:

Locals:
  child_dict : defaultdict(<type 'list'>, {})
  pid        : 5510
  processes  : [['1', '0', 'Ss'], ['15', '1', 'Ss'], ['16', '1', 'Ss'], ['17 ... 99', 'R+'], ['78347', '78344', 'Ss'], ['78349', '78347', 'S']] (truncated)

ValueError: need more than 3 values to unpack
---------------------------

BUG=

Committed: https://src.chromium.org/viewvc/chrome?view=rev&revision=234648

[tonyg, 2013-11-12 17:34:53]

I was going to wrap one flaky area in a try-except to print out some local
variables, then thought that there has to be a better way. This fell out.

BTW, rietveld kills the formatting. If you click edit issue, it shows properly.

[bulach, 2013-11-12 18:10:05]

lgtm, looks great, thanks!!

just some minor suggestions, freel free to ignore them as they're more personal
preferences than anything else..

also, perhaps put the long description in a bug rather than embedded here...

https://codereview.chromium.org/64553004/diff/1/tools/telemetry/telemetry/tes...
File tools/telemetry/telemetry/test_runner.py (right):

https://codereview.chromium.org/64553004/diff/1/tools/telemetry/telemetry/tes...
tools/telemetry/telemetry/test_runner.py:50: print >> sys.stderr, '  %s at
%s:%d' % (function, filename, line)
how about keeping the same format, just so we stick to the standard? :)

File "tools/perf/../telemetry/telemetry/test_runner.py", line 290, in Main

https://codereview.chromium.org/64553004/diff/1/tools/telemetry/telemetry/tes...
tools/telemetry/telemetry/test_runner.py:62: possibly_truncated_value =
value[:100]
would it be too complicated to also print the last 100th too?
it should be rare, but would potentially be valuable, wdyt?

https://codereview.chromium.org/64553004/diff/1/tools/telemetry/telemetry/tes...
tools/telemetry/telemetry/test_runner.py:71: print >> sys.stderr
nit: perhaps:

print >> sys.stderr, "Raw Exception: "

[tonyg, 2013-11-12 19:23:45]

https://codereview.chromium.org/64553004/diff/1/tools/telemetry/telemetry/tes...
File tools/telemetry/telemetry/test_runner.py (right):

https://codereview.chromium.org/64553004/diff/1/tools/telemetry/telemetry/tes...
tools/telemetry/telemetry/test_runner.py:50: print >> sys.stderr, '  %s at
%s:%d' % (function, filename, line)
On 2013/11/12 18:10:05, bulach wrote:
> how about keeping the same format, just so we stick to the standard? :)
> 
> File "tools/perf/../telemetry/telemetry/test_runner.py", line 290, in Main 

I like the new format so much better. The old one always bugged me. I'm going to
try this new one and see if anyone complains.

https://codereview.chromium.org/64553004/diff/1/tools/telemetry/telemetry/tes...
tools/telemetry/telemetry/test_runner.py:62: possibly_truncated_value =
value[:100]
On 2013/11/12 18:10:05, bulach wrote:
> would it be too complicated to also print the last 100th too?
> it should be rare, but would potentially be valuable, wdyt?

Great point! I elide in the middle instead of at the end now.

https://codereview.chromium.org/64553004/diff/1/tools/telemetry/telemetry/tes...
tools/telemetry/telemetry/test_runner.py:71: print >> sys.stderr
On 2013/11/12 18:10:05, bulach wrote:
> nit: perhaps:
> 
> print >> sys.stderr, "Raw Exception: "

I don't think this is necessary.

[commit-bot: I haz the power, 2013-11-12 19:30:01]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/tonyg@chromium.org/64553004/60001

[commit-bot: I haz the power, 2013-11-12 22:06:50]

Change committed as 234648