[Telemetry][Tracing] Split StopTracing and CollectTraceData for Chrome Tracing Agent.

[Telemetry][Tracing] Split StopTracing and CollectTraceData for Chrome Tracing Agent.

BUG=catapult:#2219

Committed: https://chromium.googlesource.com/external/github.com/catapult-project/catapult/+/9e84e9f4d0120e980c94b99fdaf287c729d0fe97

[rnephew (Reviews Here), 2016-07-19 21:49:09]

rnephew@chromium.org changed reviewers:
+ charliea@chromium.org, nednguyen@google.com, zhenw@chromium.org

[rnephew (Reviews Here), 2016-07-19 21:49:10]

This will also help with speeding up battor runs. It decreases the length of the
chrome trace significantly in the following case:

Start Battor Tracing
Start Chrome Tracing
Stop Battor Tracing
Stop Chrome Tracing
Collect Battor Tracing
Collect Chrome Tracing

This is because before this, it will stop chrome tracing during the collect
chrome tracing step, and chrome tracing would continue to run while battor data
is being downloaded.

I have some traces that demonstrate this decrease in chrome trace.

[Zhen Wang, 2016-07-19 23:38:51]

https://codereview.chromium.org/2160953003/diff/20001/telemetry/telemetry/int...
File
telemetry/telemetry/internal/backends/chrome_inspector/devtools_client_backend.py
(right):

https://codereview.chromium.org/2160953003/diff/20001/telemetry/telemetry/int...
telemetry/telemetry/internal/backends/chrome_inspector/devtools_client_backend.py:346:
def CollectChromeTracing(self, trace_data_builder, timeout=30):
s/CollectChromeTracing/CollectChromeTracingData

https://codereview.chromium.org/2160953003/diff/20001/telemetry/telemetry/int...
File telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py
(right):

https://codereview.chromium.org/2160953003/diff/20001/telemetry/telemetry/int...
telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py:167:
self._is_tracing_running = False
We probably want to add a check for pending data in collection phase. We do not
want to allow devtools or tracing backend to start tracing during data
collection phase.

https://codereview.chromium.org/2160953003/diff/20001/telemetry/telemetry/int...
File telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py
(right):

https://codereview.chromium.org/2160953003/diff/20001/telemetry/telemetry/int...
telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py:55:
self._active_devtools = []
"active" make me think tracing is still active, which is not the case here.
Maybe "_data_collection_devtools"? (I feel this name does not sound right, maybe
try some other name).

https://codereview.chromium.org/2160953003/diff/20001/telemetry/telemetry/int...
telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py:236:
'\n'.join(raised_exception_messages))
need to clear self._active_devtools after collection.

[rnephew (Reviews Here), 2016-07-21 16:46:30]

Patchset #3 (id:40001) has been deleted

[rnephew (Reviews Here), 2016-07-21 16:53:41]

Patchset #3 (id:60001) has been deleted

[rnephew (Reviews Here), 2016-07-21 17:05:50]

Patchset #3 (id:80001) has been deleted

[rnephew (Reviews Here), 2016-07-21 17:06:00]

https://codereview.chromium.org/2160953003/diff/20001/telemetry/telemetry/int...
File
telemetry/telemetry/internal/backends/chrome_inspector/devtools_client_backend.py
(right):

https://codereview.chromium.org/2160953003/diff/20001/telemetry/telemetry/int...
telemetry/telemetry/internal/backends/chrome_inspector/devtools_client_backend.py:346:
def CollectChromeTracing(self, trace_data_builder, timeout=30):
On 2016/07/19 23:38:50, Zhen Wang wrote:
> s/CollectChromeTracing/CollectChromeTracingData

Done.

https://codereview.chromium.org/2160953003/diff/20001/telemetry/telemetry/int...
File telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py
(right):

https://codereview.chromium.org/2160953003/diff/20001/telemetry/telemetry/int...
telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py:167:
self._is_tracing_running = False
On 2016/07/19 23:38:50, Zhen Wang wrote:
> We probably want to add a check for pending data in collection phase. We do
not
> want to allow devtools or tracing backend to start tracing during data
> collection phase.

Done.

https://codereview.chromium.org/2160953003/diff/20001/telemetry/telemetry/int...
File telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py
(right):

https://codereview.chromium.org/2160953003/diff/20001/telemetry/telemetry/int...
telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py:55:
self._active_devtools = []
On 2016/07/19 23:38:50, Zhen Wang wrote:
> "active" make me think tracing is still active, which is not the case here.
> Maybe "_data_collection_devtools"? (I feel this name does not sound right,
maybe
> try some other name).

Done.

https://codereview.chromium.org/2160953003/diff/20001/telemetry/telemetry/int...
telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py:236:
'\n'.join(raised_exception_messages))
On 2016/07/19 23:38:50, Zhen Wang wrote:
> need to clear self._active_devtools after collection.

Done.

[rnephew (Reviews Here), 2016-07-21 18:19:31]

I ran locally to get some information on the time decrease. Most of the
increased time to run battor seems to be fixed with this.

date +%s; ./run_benchmark battor.power_cases --browser=android-chrome
--output-format=html --output-format=json --story-filter=webkit; date +%s
Time running one page with changes:
1469121778 - 1469121715 = 63
1469122406 - 1469122342 = 64
1469122498 - 1469122433 = 65
1469122606 - 1469122541 = 65
avg: 64.25

Time running one page without changes:
1469122722 - 1469122649 = 73
1469122843 - 1469122767 = 76
1469122937 - 1469122862 = 75
1469123045 - 1469122970 = 75
avg: 74.75

Percent Decrease on avg: ~14.0%


date +%s; ./run_benchmark battor.power_cases --browser=android-chrome
--output-format=html --output-format=json; date +%s
Time running all pages with changes:
1469124495 - 1469124335 = 160
1469124683 - 1469124521 = 162
1469124882 - 1469124720 = 162
1469125048 - 1469124888 = 160
avg: 161

Time running all pages without changes:
1469123265 - 1469123087 = 178
1469123667 - 1469123489 = 178
1469124017 - 1469123842 = 175
1469124228 - 1469124048 = 180
avg: 177.75

Percent Decrease on avg: ~9.4%


Note: The reason why the difference (IMO) is not ~3x the single page run is
likely because about:blank does not contain much information in its chrome
trace; thus does not benefit much from this improvement.

[rnephew (Reviews Here), 2016-07-21 18:20:46]

rnephew@chromium.org changed reviewers:
+ aschulman@chromium.org

[Zhen Wang, 2016-07-21 19:45:19]

https://codereview.chromium.org/2160953003/diff/100001/telemetry/telemetry/in...
File
telemetry/telemetry/internal/backends/chrome_inspector/devtools_client_backend.py
(right):

https://codereview.chromium.org/2160953003/diff/100001/telemetry/telemetry/in...
telemetry/telemetry/internal/backends/chrome_inspector/devtools_client_backend.py:107:
self._tab_ids = None
Does this tab id thing come from rebase?

https://codereview.chromium.org/2160953003/diff/100001/telemetry/telemetry/in...
File telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py
(right):

https://codereview.chromium.org/2160953003/diff/100001/telemetry/telemetry/in...
telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py:100:
self._can_collect = False
Can we combine those two? We should not allow new tracing session if previous
tracing is stopped and data is not collected, which simplifies the use case
here.

https://codereview.chromium.org/2160953003/diff/100001/telemetry/telemetry/in...
File telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py
(right):

https://codereview.chromium.org/2160953003/diff/100001/telemetry/telemetry/in...
telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py:201:
for client in devtools_clients:
Probably assert self._previously_responsive_devtools is empty before the for
loop.

[rnephew (Reviews Here), 2016-07-21 19:55:20]

https://codereview.chromium.org/2160953003/diff/100001/telemetry/telemetry/in...
File
telemetry/telemetry/internal/backends/chrome_inspector/devtools_client_backend.py
(right):

https://codereview.chromium.org/2160953003/diff/100001/telemetry/telemetry/in...
telemetry/telemetry/internal/backends/chrome_inspector/devtools_client_backend.py:107:
self._tab_ids = None
On 2016/07/21 19:45:19, Zhen Wang wrote:
> Does this tab id thing come from rebase?

No, it was required to fix a failing test this CL introduced. This is populated
in StopChromeTracing (javascript needs to be evaluated before stopping chrome
tracing) and used in CollectChromeTracingData to add things to the
trace_data_builder (cant be done in StopChromeTracing since it no longer gets
passed the trace_data_builder.)

https://codereview.chromium.org/2160953003/diff/100001/telemetry/telemetry/in...
File telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py
(right):

https://codereview.chromium.org/2160953003/diff/100001/telemetry/telemetry/in...
telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py:100:
self._can_collect = False
On 2016/07/21 19:45:19, Zhen Wang wrote:
> Can we combine those two? We should not allow new tracing session if previous
> tracing is stopped and data is not collected, which simplifies the use case
> here.

Done.

https://codereview.chromium.org/2160953003/diff/100001/telemetry/telemetry/in...
File telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py
(right):

https://codereview.chromium.org/2160953003/diff/100001/telemetry/telemetry/in...
telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py:201:
for client in devtools_clients:
On 2016/07/21 19:45:19, Zhen Wang wrote:
> Probably assert self._previously_responsive_devtools is empty before the for
> loop.

Done.

[Zhen Wang, 2016-07-21 21:54:55]

https://codereview.chromium.org/2160953003/diff/120001/telemetry/telemetry/in...
File telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py
(right):

https://codereview.chromium.org/2160953003/diff/120001/telemetry/telemetry/in...
telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py:99:
self._can_collect = False
nit:
1. move this after _is_tracing_running
2. rename to _can_collect_data

https://codereview.chromium.org/2160953003/diff/120001/telemetry/telemetry/in...
telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py:110:
if self.is_tracing_running or self._can_collect:
After the is_tracing_running check, we should probably assert self._can_collect
to be false.

The reason is that we should always collect data right after stopping tracing.
If _can_collect is true here, we are doing something wrong.

https://codereview.chromium.org/2160953003/diff/120001/telemetry/telemetry/in...
File telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py
(right):

https://codereview.chromium.org/2160953003/diff/120001/telemetry/telemetry/in...
telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py:238:
self._previously_responsive_devtools = []
This should be before the if statement.

[rnephew (Reviews Here), 2016-07-21 22:02:08]

https://codereview.chromium.org/2160953003/diff/120001/telemetry/telemetry/in...
File telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py
(right):

https://codereview.chromium.org/2160953003/diff/120001/telemetry/telemetry/in...
telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py:99:
self._can_collect = False
On 2016/07/21 21:54:55, Zhen Wang wrote:
> nit:
> 1. move this after _is_tracing_running
> 2. rename to _can_collect_data

Done.

https://codereview.chromium.org/2160953003/diff/120001/telemetry/telemetry/in...
telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py:110:
if self.is_tracing_running or self._can_collect:
On 2016/07/21 21:54:55, Zhen Wang wrote:
> After the is_tracing_running check, we should probably assert
self._can_collect
> to be false.
> 
> The reason is that we should always collect data right after stopping tracing.
> If _can_collect is true here, we are doing something wrong.

Done.

https://codereview.chromium.org/2160953003/diff/120001/telemetry/telemetry/in...
File telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py
(right):

https://codereview.chromium.org/2160953003/diff/120001/telemetry/telemetry/in...
telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py:238:
self._previously_responsive_devtools = []
On 2016/07/21 21:54:55, Zhen Wang wrote:
> This should be before the if statement.

Done.

[Zhen Wang, 2016-07-21 22:43:51]

https://codereview.chromium.org/2160953003/diff/140001/telemetry/telemetry/in...
File telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py
(right):

https://codereview.chromium.org/2160953003/diff/140001/telemetry/telemetry/in...
telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py:112: #
Reset collected tracing data from previous tracing calls.
This comment should be right before self._trace_events = []

https://codereview.chromium.org/2160953003/diff/140001/telemetry/telemetry/in...
telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py:113:
assert not self._can_collect_data
Can you also add some error message to explain why we assert it here? Something
like:

assert not self._can_collect_data, 'There are data not collected from the
previous tracing session.'

And can you add a test for this?

[rnephew (Reviews Here), 2016-07-21 23:04:23]

https://codereview.chromium.org/2160953003/diff/140001/telemetry/telemetry/in...
File telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py
(right):

https://codereview.chromium.org/2160953003/diff/140001/telemetry/telemetry/in...
telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py:112: #
Reset collected tracing data from previous tracing calls.
On 2016/07/21 22:43:51, Zhen Wang wrote:
> This comment should be right before self._trace_events = []

Done.

https://codereview.chromium.org/2160953003/diff/140001/telemetry/telemetry/in...
telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend.py:113:
assert not self._can_collect_data
On 2016/07/21 22:43:50, Zhen Wang wrote:
> Can you also add some error message to explain why we assert it here?
Something
> like:
> 
> assert not self._can_collect_data, 'There are data not collected from the
> previous tracing session.'
> 
> And can you add a test for this?

Done.

[Zhen Wang, 2016-07-21 23:10:27]

Thanks! lgtm. One last nit.

https://codereview.chromium.org/2160953003/diff/160001/telemetry/telemetry/in...
File
telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend_unittest.py
(right):

https://codereview.chromium.org/2160953003/diff/160001/telemetry/telemetry/in...
telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend_unittest.py:205:
with self.assertRaises(AssertionError):
Can you also assert the message raised to make sure it is the right assertion we
expect?

[rnephew (Reviews Here), 2016-07-21 23:52:48]

https://codereview.chromium.org/2160953003/diff/160001/telemetry/telemetry/in...
File
telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend_unittest.py
(right):

https://codereview.chromium.org/2160953003/diff/160001/telemetry/telemetry/in...
telemetry/telemetry/internal/backends/chrome_inspector/tracing_backend_unittest.py:205:
with self.assertRaises(AssertionError):
On 2016/07/21 23:10:27, Zhen Wang wrote:
> Can you also assert the message raised to make sure it is the right assertion
we
> expect?

Done.

[rnephew (Reviews Here), 2016-07-21 23:53:05]

The CQ bit was checked by rnephew@chromium.org

[rnephew (Reviews Here), 2016-07-21 23:53:05]

The patchset sent to the CQ was uploaded after l-g-t-m from zhenw@chromium.org
Link to the patchset: https://codereview.chromium.org/2160953003/#ps180001
(title: "[Telemetry][Tracing] Split StopTracing and CollectTraceData for Chrome
Tracing Agent.")

[commit-bot: I haz the power, 2016-07-21 23:53:14]

CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2016-07-21 23:58:22]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2016-07-21 23:58:23]

Try jobs failed on following builders:
  Catapult Mac Tryserver on master.tryserver.client.catapult (JOB_FAILED,
https://build.chromium.org/p/tryserver.client.catapult/builders/Catapult%20Ma...)

[rnephew (Reviews Here), 2016-07-22 14:04:43]

The CQ bit was checked by rnephew@chromium.org

[commit-bot: I haz the power, 2016-07-22 14:04:51]

CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2016-07-22 14:30:29]

Description was changed from

==========
[Telemetry][Tracing] Split StopTracing and CollectTraceData for Chrome Tracing
Agent.

BUG=catapult:#2219
==========

to

==========
[Telemetry][Tracing] Split StopTracing and CollectTraceData for Chrome Tracing
Agent.

BUG=catapult:#2219

Committed:
https://chromium.googlesource.com/external/github.com/catapult-project/catapu...
==========

[commit-bot: I haz the power, 2016-07-22 14:30:31]

Committed patchset #7 (id:180001) as
https://chromium.googlesource.com/external/github.com/catapult-project/catapu...