[ChromeDriver] Implementing tracing support

[ChromeDriver] Implementing tracing support

BUG=

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

[johnmoore, 2014-08-08 19:23:39]

Hi Sam, Shuotao,

This is the final CL for ChromeDriver tracing support. Tests will follow soon,
but I wanted to get the implementation to you ASAP since I only have 2 weeks
left to revise it. I'll work on documentation after tests. We've discussed most
of the implementation details, and the design doc should be up-to-date with this
implementation, but questions are welcome as always.

[stgao, 2014-08-10 02:37:04]

Hi John,

I posted a few comments.
But overall, this CL looks good.

Thanks,
Shuotao Gao

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
File chrome/test/chromedriver/performance_logger.cc (right):

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:28: const char* const
kRequestTraceCommands[] = {"GetLog" /* required */,
Just an idea: do we want this to be configurable in the performance preference
setting?

But in that case, user needs to figure out the command names by browsing the
source code of chromedriver.

The benefit is we don't have to change the code when we decide to whitelist
another command.

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:43: bool
ShouldRequestTraceEvents(const std::string& method) {
|method| -> |command|?

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:159: 
This line could be removed.

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:179: "Received DevTools trace
data in unexpected format");
error message usually starts with lowercase unless it is a special name like
"DevTools".

Please also check other error messages in this CL.

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:199: if (buffer_usage >= 1.0) {
Floating point comparison is not accurate.
Maybe use > 0.99999 instead >= 1.0

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:200: LOG(WARNING) << "Chrome's
trace buffer filled while collecting events, "
This warning is on server side.

Do we want to make it available to the client side?

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:224: // We're not yet able to
tell the Chrome version, so don't report this error.
Maybe add an empty line before this one.

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:238:
params.SetInteger("bufferUsageReportingInterval", 1000 /* milliseconds */);
Will this be too frequent?

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:251: return Status(kUnknownError,
"PerformanceLogger::CollectTraceEvents called,"
Maybe remove PerformanceLogger::CollectTraceEvents from the error message. It is
implementation detail, we don't have to include it in the error message.

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:260: // Block up to 30 seconds
until Tracing.tracingComplete event is received.
Add an empty line for each logic block.
That will make the code easier to understand.

[johnmoore, 2014-08-11 16:00:02]

Hi Shuotao, Sam,

Thanks for a quick initial review! I will add tests today, but wanted to address
your comments first. There are two unresolved comments, which I will address in
the next patch set or after another round of comments. Thanks!

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
File chrome/test/chromedriver/performance_logger.cc (right):

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:28: const char* const
kRequestTraceCommands[] = {"GetLog" /* required */,
On 2014/08/10 02:37:03, Shuotao wrote:
> Just an idea: do we want this to be configurable in the performance preference
> setting?
> 
> But in that case, user needs to figure out the command names by browsing the
> source code of chromedriver.
> 
> The benefit is we don't have to change the code when we decide to whitelist
> another command.

I don't think we should expose something that complicated to the user. But maybe
we can expose a boolean flag to choose between using this hard-coded whitelist
and just dumping on every WebDriver command? That way if a particular test fills
the buffer consistently, the user could just dump on every command by passing in
a flag.

If we do this, which should be the default (whitelist or every command)?

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:43: bool
ShouldRequestTraceEvents(const std::string& method) {
On 2014/08/10 02:37:03, Shuotao wrote:
> |method| -> |command|?

Done.

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:159: 
On 2014/08/10 02:37:04, Shuotao wrote:
> This line could be removed.

Done.

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:179: "Received DevTools trace
data in unexpected format");
On 2014/08/10 02:37:03, Shuotao wrote:
> error message usually starts with lowercase unless it is a special name like
> "DevTools".
> 
> Please also check other error messages in this CL.

Done.

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:199: if (buffer_usage >= 1.0) {
On 2014/08/10 02:37:04, Shuotao wrote:
> Floating point comparison is not accurate.
> Maybe use > 0.99999 instead >= 1.0

Done.

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:200: LOG(WARNING) << "Chrome's
trace buffer filled while collecting events, "
On 2014/08/10 02:37:04, Shuotao wrote:
> This warning is on server side.
> 
> Do we want to make it available to the client side?

Good idea. I've exposed the message to the user by adding it to the performance
log. I was careful to use the same formatting as other log entries (by making it
an entry for the browser webview with method Tracing.bufferUsage), as described
in performance_logger.h. This way clients won't fail when they expect that JSON
format.

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:224: // We're not yet able to
tell the Chrome version, so don't report this error.
On 2014/08/10 02:37:04, Shuotao wrote:
> Maybe add an empty line before this one.

Done.

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:238:
params.SetInteger("bufferUsageReportingInterval", 1000 /* milliseconds */);
On 2014/08/10 02:37:03, Shuotao wrote:
> Will this be too frequent?

This is the default value that I've seen used in Chromium (e.g. about://tracing
and //src/content/browser/devtools/devtools_tracing_handler.cc and elsewhere).
It's true that the server and client will then receive an error for every second
that the buffer is full, but maybe that's a good thing: they can then estimate
just how much trace data was lost, if they'd like, by looking at how many errors
there are.

If we raise the default, perhaps we should make this value another perf log
pref, since I'm sure some users will want 1000 ms. I'm happy to do that if you
think it'd be appropriate.

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:251: return Status(kUnknownError,
"PerformanceLogger::CollectTraceEvents called,"
On 2014/08/10 02:37:03, Shuotao wrote:
> Maybe remove PerformanceLogger::CollectTraceEvents from the error message. It
is
> implementation detail, we don't have to include it in the error message.

Done.

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:260: // Block up to 30 seconds
until Tracing.tracingComplete event is received.
On 2014/08/10 02:37:03, Shuotao wrote:
> Add an empty line for each logic block.
> That will make the code easier to understand.

Done.

[johnmoore, 2014-08-12 00:17:54]

I've added unit tests. I will try to write an integration test too, but perhaps
we should leave that for one final CL since this one is already so big.

[samuong, 2014-08-14 23:04:46]

Hi John, this is looking really good, thanks for your work on this. I've only
got one comment for your current patch set.

But I would feel better if there was an end-to-end test to go along with this
CL. I don't think that submitting the end-to-end tests together will cause any
confusion, since the test code should be in a separate set of files anyway.

https://codereview.chromium.org/454133003/diff/60001/chrome/test/chromedriver...
File chrome/test/chromedriver/performance_logger.cc (right):

https://codereview.chromium.org/454133003/diff/60001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:244: CHECK(browser_client_);
CHECK() will cause ChromeDriver to dump its stack and exit. Should we just
return an error status here instead?

https://codereview.chromium.org/454133003/diff/60001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:263: CHECK(browser_client_);
Same here.

[johnmoore, 2014-08-15 17:34:07]

Hi Shuotao, Sam,

Thanks for the continued reviews. I have added an integration test and addressed
Sam's comment. There are still two unresolved comments from Shuotao's review,
but they shouldn't take long to resolve if changes are needed.

https://codereview.chromium.org/454133003/diff/60001/chrome/test/chromedriver...
File chrome/test/chromedriver/performance_logger.cc (right):

https://codereview.chromium.org/454133003/diff/60001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:244: CHECK(browser_client_);
On 2014/08/14 23:04:46, samuong wrote:
> CHECK() will cause ChromeDriver to dump its stack and exit. Should we just
> return an error status here instead?

Done.

https://codereview.chromium.org/454133003/diff/60001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:263: CHECK(browser_client_);
On 2014/08/14 23:04:46, samuong wrote:
> Same here.

Done.

[stgao, 2014-08-15 17:43:23]

Sorry, I missed your questions.

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
File chrome/test/chromedriver/performance_logger.cc (right):

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:28: const char* const
kRequestTraceCommands[] = {"GetLog" /* required */,
On 2014/08/11 16:00:01, johnmoore wrote:
> On 2014/08/10 02:37:03, Shuotao wrote:
> > Just an idea: do we want this to be configurable in the performance
preference
> > setting?
> > 
> > But in that case, user needs to figure out the command names by browsing the
> > source code of chromedriver.
> > 
> > The benefit is we don't have to change the code when we decide to whitelist
> > another command.
> 
> I don't think we should expose something that complicated to the user. But
maybe
> we can expose a boolean flag to choose between using this hard-coded whitelist
> and just dumping on every WebDriver command? That way if a particular test
fills
> the buffer consistently, the user could just dump on every command by passing
in
> a flag.
> 
> If we do this, which should be the default (whitelist or every command)?

Not sure if we want to do every command, because some commands have no
interaction with the Chrome browser, eg: setTimeout.

Let's go with the whitelist for this CL.
Later if user complains, we could make the needed change.

https://codereview.chromium.org/454133003/diff/20001/chrome/test/chromedriver...
chrome/test/chromedriver/performance_logger.cc:238:
params.SetInteger("bufferUsageReportingInterval", 1000 /* milliseconds */);
On 2014/08/11 16:00:02, johnmoore wrote:
> On 2014/08/10 02:37:03, Shuotao wrote:
> > Will this be too frequent?
> 
> This is the default value that I've seen used in Chromium (e.g.
about://tracing
> and //src/content/browser/devtools/devtools_tracing_handler.cc and elsewhere).
> It's true that the server and client will then receive an error for every
second
> that the buffer is full, but maybe that's a good thing: they can then estimate
> just how much trace data was lost, if they'd like, by looking at how many
errors
> there are.
> 
> If we raise the default, perhaps we should make this value another perf log
> pref, since I'm sure some users will want 1000 ms. I'm happy to do that if you
> think it'd be appropriate.

Vote for making it configurable in perf log setting, with default to 1000ms.
WDYT?

[johnmoore, 2014-08-15 18:57:49]

I've added a perf logging pref for the buffer usage reporting interval, with a
default value of 1000 ms. I verify that the value is positive, since negative
values cause DevTools errors. If the user specifies a value but no trace
categories, I don't throw an error. I can change any of these design decisions
if necessary. Once submitted I will update the documentation.

[johnmoore, 2014-08-19 15:29:54]

The integration test now works with all versions of Chrome.

[samuong, 2014-08-19 18:13:21]

On 2014/08/19 15:29:54, johnmoore wrote:
> The integration test now works with all versions of Chrome.

lgtm with nits

[chromium-reviews, 2014-08-19 20:01:22]

Hi Sam,

Thanks for the LGTM. Can you clarify the nits? I didn't see any additional
comments. Thanks!


On Tue, Aug 19, 2014 at 2:13 PM, <samuong@chromium.org> wrote:

> On 2014/08/19 15:29:54, johnmoore wrote:
>
>> The integration test now works with all versions of Chrome.
>>
>
> lgtm with nits
>
> https://codereview.chromium.org/454133003/
>

To unsubscribe from this group and stop receiving emails from it, send an email
to chromium-reviews+unsubscribe@chromium.org.

[samuong, 2014-08-19 20:02:50]

Sorry, nits are below. Thanks!

https://codereview.chromium.org/454133003/diff/140001/chrome/test/chromedrive...
File chrome/test/chromedriver/performance_logger_unittest.cc (right):

https://codereview.chromium.org/454133003/diff/140001/chrome/test/chromedrive...
chrome/test/chromedriver/performance_logger_unittest.cc:237:
prefs.trace_categories = "benchmark,webkit.console";
blink.console?

https://codereview.chromium.org/454133003/diff/140001/chrome/test/chromedrive...
chrome/test/chromedriver/performance_logger_unittest.cc:313:
prefs.trace_categories = "benchmark,webkit.console";
blink.console?

https://codereview.chromium.org/454133003/diff/140001/chrome/test/chromedrive...
File chrome/test/chromedriver/test/run_py_tests.py (right):

https://codereview.chromium.org/454133003/diff/140001/chrome/test/chromedrive...
chrome/test/chromedriver/test/run_py_tests.py:934: {'Network', 'Page',
'Timeline', 'Tracing'})
can use assertEqual(expected,actual) here

[johnmoore, 2014-08-20 14:15:26]

Hi Sam, Shuotao,

I've fixed the nits. Thanks for the review! I am now only waiting on an LGTM
from Shuotao.

[stgao, 2014-08-20 17:17:39]

On 2014/08/20 14:15:26, johnmoore wrote:
> Hi Sam, Shuotao,
> 
> I've fixed the nits. Thanks for the review! I am now only waiting on an LGTM
> from Shuotao.

Hi John,

As Sam already gave a lgtm, please feel free to CQ your CL.
LGTM too.

Thanks,
Shuotao Gao

[johnmoore, 2014-08-20 17:27:35]

The CQ bit was checked by johnmoore@google.com

[commit-bot: I haz the power, 2014-08-20 17:28:22]

CQ is trying da patch. Follow status at
 https://chromium-status.appspot.com/cq/johnmoore@google.com/454133003/160001

[commit-bot: I haz the power, 2014-08-20 20:53:19]

Committed patchset #9 (160001) as 290912

[johnmoore, 2015-11-05 18:07:48]

Description was changed from

==========
[ChromeDriver] Implementing tracing support

BUG=

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

to

==========
[ChromeDriver] Implementing tracing support

BUG=

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

[johnmoore, 2015-11-05 18:07:48]

johnmoore@google.com changed reviewers:
+ hughrobinson@google.com